Dear developers,
I have been having problems that are starting to accumulate on my main
Desktop and I decided to ask here for help, since I perceive that the
majority (not all, of course) of developers are likely to use recent,
Intel-based systems for their x86-64 work.
My desktop has an AMD Phenon II X4 910 processor and a corresponding chipset
(I can provide many, many details).
Before I go on describing the problems that I have, I want to say that I can
bisect the kernel, apply patches and give feedback for the problems that I
am seeing.
The problems that I am seeing are the following:
* I have never been able to boot this computer of mine without the option
irqpoll---otherwise, I get the nobody cared message. I just didn't pay
much attention, despite me booting with many different kernels and
distributions.
With a particular Fedora, I reported the problem, but It was coalesced
with many other "nobody cared" messages and once that particular Fedora
release was EOL'ed, the bug report was closed.
* Besides the previous problem, starting with Debian's kernel 4.5, I am
seeing bazillion messages like the following:
(...)
[ 198.701170] hpet_rtc_timer_reinit: 3 callbacks suppressed
[ 198.701180] hpet1: lost 9 rtc interrupts
[ 198.893025] hpet1: lost 6 rtc interrupts
[ 199.261331] hpet1: lost 18 rtc interrupts
[ 199.421005] hpet1: lost 5 rtc interrupts
[ 200.301213] hpet1: lost 38 rtc interrupts
[ 200.620908] hpet1: lost 10 rtc interrupts
[ 200.780805] hpet1: lost 4 rtc interrupts
[ 201.020950] hpet1: lost 9 rtc interrupts
[ 201.132796] hpet1: lost 2 rtc interrupts
[ 201.420817] hpet1: lost 12 rtc interrupts
[ 203.818978] hpet_rtc_timer_reinit: 6 callbacks suppressed
[ 203.818988] hpet1: lost 9 rtc interrupts
[ 204.332489] hpet1: lost 13 rtc interrupts
[ 204.859603] hpet1: lost 28 rtc interrupts
[ 205.452624] hpet1: lost 33 rtc interrupts
[ 205.580324] hpet1: lost 3 rtc interrupts
[ 206.332410] hpet1: lost 42 rtc interrupts
[ 206.457489] hpet1: lost 3 rtc interrupts
[ 206.652160] hpet1: lost 7 rtc interrupts
[ 206.812568] hpet1: lost 4 rtc interrupts
[ 206.972045] hpet1: lost 4 rtc interrupts
[ 208.907139] hpet_rtc_timer_reinit: 3 callbacks suppressed
[ 208.907150] hpet1: lost 48 rtc interrupts
[ 213.469016] hpet1: lost 291 rtc interrupts
[ 214.186567] hpet1: lost 43 rtc interrupts
[ 214.984415] hpet1: lost 42 rtc interrupts
[ 215.304994] hpet1: lost 13 rtc interrupts
[ 217.448507] hpet1: lost 3 rtc interrupts
[ 218.247600] hpet1: lost 48 rtc interrupts
(...)
I tested this with Ubuntu's pre-compiled/unpatched kernel 4.5-rc1 and I
also get this problem, but with slightly different messages (which I guess
are due to debugging being enabled):
(...)
[ 371.320075] evbug: Event. Dev: input6, Type: 4, Code: 4, Value: 458760
[ 371.320079] evbug: Event. Dev: input6, Type: 1, Code: 18, Value: 0
[ 371.320081] evbug: Event. Dev: input6, Type: 0, Code: 0, Value: 0
[ 371.448069] evbug: Event. Dev: input6, Type: 4, Code: 4, Value: 458774
[ 371.448072] evbug: Event. Dev: input6, Type: 1, Code: 31, Value: 1
[ 371.448074] evbug: Event. Dev: input6, Type: 0, Code: 0, Value: 0
[ 371.480062] evbug: Event. Dev: input6, Type: 4, Code: 4, Value: 458774
[ 371.480067] evbug: Event. Dev: input6, Type: 1, Code: 31, Value: 0
[ 371.480069] evbug: Event. Dev: input6, Type: 0, Code: 0, Value: 0
[ 371.608060] evbug: Event. Dev: input6, Type: 4, Code: 4, Value: 458774
[ 371.608064] evbug: Event. Dev: input6, Type: 1, Code: 31, Value: 1
[ 371.608066] evbug: Event. Dev: input6, Type: 0, Code: 0, Value: 0
[ 371.688057] evbug: Event. Dev: input6, Type: 4, Code: 4, Value: 458774
[ 371.688061] evbug: Event. Dev: input6, Type: 1, Code: 31, Value: 0
[ 371.688063] evbug: Event. Dev: input6, Type: 0, Code: 0, Value: 0
[ 371.768051] evbug: Event. Dev: input6, Type: 4, Code: 4, Value: 458792
[ 371.768055] evbug: Event. Dev: input6, Type: 1, Code: 28, Value: 1
[ 371.768057] evbug: Event. Dev: input6, Type: 0, Code: 0, Value: 0
[ 371.786065] hpet1: lost 90 rtc interrupts
[ 371.803655] evbug: Event. Dev: input6, Type: 4, Code: 4, Value: 458792
[ 371.803660] evbug: Event. Dev: input6, Type: 1, Code: 28, Value: 0
[ 371.803662] evbug: Event. Dev: input6, Type: 0, Code: 0, Value: 0
[ 372.194719] hpet1: lost 23 rtc interrupts
[ 373.527954] evbug: Event. Dev: input6, Type: 4, Code: 4, Value: 458827
[ 373.527958] evbug: Event. Dev: input6, Type: 1, Code: 104, Value: 1
[ 373.527961] evbug: Event. Dev: input6, Type: 0, Code: 0, Value: 0
[ 373.607943] evbug: Event. Dev: input6, Type: 4, Code: 4, Value: 458827
[ 373.607947] evbug: Event. Dev: input6, Type: 1, Code: 104, Value: 0
[ 373.607949] evbug: Event. Dev: input6, Type: 0, Code: 0, Value: 0
[ 373.895924] evbug: Event. Dev: input6, Type: 4, Code: 4, Value: 458827
[ 373.895928] evbug: Event. Dev: input6, Type: 1, Code: 104, Value: 1
[ 373.895930] evbug: Event. Dev: input6, Type: 0, Code: 0, Value: 0
[ 373.959913] evbug: Event. Dev: input6, Type: 4, Code: 4, Value: 458827
[ 373.959917] evbug: Event. Dev: input6, Type: 1, Code: 104, Value: 0
[ 373.959920] evbug: Event. Dev: input6, Type: 0, Code: 0, Value: 0
[ 374.087908] evbug: Event. Dev: input6, Type: 4, Code: 4, Value: 458827
[ 374.087911] evbug: Event. Dev: input6, Type: 1, Code: 104, Value: 1
[ 374.087913] evbug: Event. Dev: input6, Type: 0, Code: 0, Value: 0
[ 374.199899] evbug: Event. Dev: input6, Type: 4, Code: 4, Value: 458827
(...)
I reported the problem above at
https://bugzilla.kernel.org/show_bug.cgi?id=120251 in June, when I was
running Debian's kernel 4.6.
I included many details there about my hardware configuration, but, of
course, I can copy them here in email for convenience.
* Besides *both* problems listed above, starting with Debian's kernel 4.8, I
am seeing a very strange problem: when I was scanning some documents on my
(USB) HP PSC 1610, it *always* hangs within about 15% of the work done.
I discovered this while, as a single father, scanning some spiderman
drawings to let my 4 y.o. boy, so that he could paint on them.
This is 100% reproducible with kernel 4.8 and, with kernel 4.7 (dropped
from Debian's next release), I don't have this 3rd problem.
Once again, I can bisect the kernel, apply patches and give feedback for the
problems that I am seeing. Just let me know what is necessary and I will do
what I'm instructed.
Please, keep me CC'ed as I'm not currently subscribed to the mailing lists.
Also, feel free to drop/adjust the list of recipients as appropriate.
Thanks a lot,
--
Rogério Brito : rbrito@{ime.usp.br,gmail.com} : GPG key 4096R/BCFCAAAA
http://rb.doesntexist.org/blog : Projects : https://github.com/rbrito/
DebianQA: http://qa.debian.org/developer.php?login=rbrito%40ime.usp.br
On Thu, Nov 24, 2016 at 09:39:57PM -0200, Rogério Brito wrote:
> Before I go on describing the problems that I have, I want to say that I can
> bisect the kernel, apply patches and give feedback for the problems that I
> am seeing.
Good. We're going to need them.
Please checkout lates Linus kernel:
http://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git
build it, boot it on your machine, catch dmesg and send it to me.
Thanks!
--
Regards/Gruss,
Boris.
Good mailing practices for 400: avoid top-posting and trim the reply.
Rogério Brito wrote:
> * I have never been able to boot this computer of mine without the option
> irqpoll---otherwise, I get the nobody cared message.
The "nobody cared" message indicates that there were too many interrupts
that no driver felt responsible for, so the kernel has disabled that
interrupt vector. The irqpoll option is a workaround to get the devices
on that interrupt vector to work, but it's not perfect.
It's possible that most of your problems are caused by the irqpoll option.
What IRQ is the problematic one (see the "nobody cared" message)? What
devices are connected to it (see /proc/interrupts)? Does the problem go
away when you prevent the corresponding driver(s) from loading?
Regards,
Clemens
Dear Boris and Clemens,
First of all, thank you very much for your replies. They are very much
appreciated.
On Nov 25 2016, Borislav Petkov wrote:
> On Thu, Nov 24, 2016 at 09:39:57PM -0200, Rogério Brito wrote:
> > Before I go on describing the problems that I have, I want to say that I can
> > bisect the kernel, apply patches and give feedback for the problems that I
> > am seeing.
>
> Good. We're going to need them.
Great. I'm willing to do that.
In fact, I have quite a few computers that are not running Linux that well
at this moment and I guess that lack of report from final users (or,
perhaps, reports being lost in the way) prevents those problems from getting
fixed.
Ihope that my efforts will help other users to have fewer problems with
Linux on older machines, at least.
> Please checkout lates Linus kernel:
>
> http://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git
>
> build it, boot it on your machine, catch dmesg and send it to me.
To speed things up a bit, I grabbed Ubuntu's precompiled 4.8 and 4.9-rc6
(without any patches on top of Linus's tree) and booted on this machine.
The scanner problem is still there with vanilla 4.8 (with the irqpoll
option), but is gone with vanilla 4.9-rc6 (with the irqpoll option).
I guess that backports of fixes to this (once detected) are needed for
-stable kernels that distributions are shipping with?
The other problems ("nobody cared" and the flood of evbug/lost xx rtc
interrupts messages) remain with 4.9-rc6.
Interestingly, for a layman like me:
* if I remove the irqpoll option, the "hpet1: lost xx rtc interrupts" messages
are gone, but I still get messages like
[ 130.007219] evbug: Event. Dev: input6, Type: 0, Code: 0, Value: 0
[ 130.167191] evbug: Event. Dev: input6, Type: 4, Code: 4, Value: 458767
[ 130.167195] evbug: Event. Dev: input6, Type: 1, Code: 38, Value: 1
[ 130.167197] evbug: Event. Dev: input6, Type: 0, Code: 0, Value: 0
[ 130.247174] evbug: Event. Dev: input6, Type: 4, Code: 4, Value: 458767
* if I keep the irqpoll option, I get both "hpet1: lost xx rtc interrupts"
AND the evbug messages remain.
I'm attaching the dmesg of 4.9-rc6 both with and without irqpoll to this
message.
I'm now going to chase the information regarding /proc/interrupts that
Clemens asked about.
Thanks,
--
Rogério Brito : rbrito@{ime.usp.br,gmail.com} : GPG key 4096R/BCFCAAAA
http://rb.doesntexist.org/blog : Projects : https://github.com/rbrito/
DebianQA: http://qa.debian.org/developer.php?login=rbrito%40ime.usp.br
Rogério Brito wrote:
> [ 130.007219] evbug: Event. Dev: input6, Type: 0, Code: 0, Value: 0
The evbug module is intended for debugging; it dumps all input events
into syslog. If you do not want these messages, do not load this module.
(If it is loaded automatically, you have an actual bug.)
Regards,
Clemens
On Fri, Nov 25, 2016 at 02:05:48PM -0200, Rogério Brito wrote:
> In fact, I have quite a few computers that are not running Linux that well
> at this moment and I guess that lack of report from final users (or,
> perhaps, reports being lost in the way) prevents those problems from getting
> fixed.
CC me on those, I'd take a look.
> Ihope that my efforts will help other users to have fewer problems with
> Linux on older machines, at least.
> To speed things up a bit, I grabbed Ubuntu's precompiled 4.8 and 4.9-rc6
> (without any patches on top of Linus's tree) and booted on this machine.
>
> The scanner problem is still there with vanilla 4.8 (with the irqpoll
> option), but is gone with vanilla 4.9-rc6 (with the irqpoll option).
Does -rc6 work *without* irqpoll?
Also, you can diff dmesg from both kernels and see whether you can spot
something relevant.
> I guess that backports of fixes to this (once detected) are needed for
> -stable kernels that distributions are shipping with?
Yes, once we know what fixes the issues.
> The other problems ("nobody cared" and the flood of evbug/lost xx rtc
> interrupts messages) remain with 4.9-rc6.
>
> Interestingly, for a layman like me:
>
> * if I remove the irqpoll option, the "hpet1: lost xx rtc interrupts" messages
Aha, so irqpoll is crap. Just remove it.
> are gone, but I still get messages like
>
> [ 130.007219] evbug: Event. Dev: input6, Type: 0, Code: 0, Value: 0
> [ 130.167191] evbug: Event. Dev: input6, Type: 4, Code: 4, Value: 458767
> [ 130.167195] evbug: Event. Dev: input6, Type: 1, Code: 38, Value: 1
> [ 130.167197] evbug: Event. Dev: input6, Type: 0, Code: 0, Value: 0
> [ 130.247174] evbug: Event. Dev: input6, Type: 4, Code: 4, Value: 458767
>
> * if I keep the irqpoll option, I get both "hpet1: lost xx rtc interrupts"
> AND the evbug messages remain.
Just blacklist that module, it is for debugging input events.
> I'm attaching the dmesg of 4.9-rc6 both with and without irqpoll to this
> message.
Thanks.
[ 0.000000] DMI: To Be Filled By O.E.M. To Be Filled By O.E.M./To be filled by O.E.M., BIOS 0500 05/11/2010
Has your BIOS *ever* been updated? If not, why not?
Yap, that BIOS is "fun":
[ 0.000000] Aperture pointing to e820 RAM. Ignoring.
[ 0.000000] AGP: Your BIOS doesn't leave an aperture memory hole
[ 0.000000] AGP: Please enable the IOMMU option in the BIOS setup
[ 0.000000] AGP: This costs you 64MB of RAM
Do you have an IOMMU option in your BIOS?
[ 30.434052] usblp 5-2:1.1: usblp1: USB Bidirectional printer dev 2 if 1 alt 0 proto 2 vid 0x03F0 pid 0x4811
[ 34.157510] irq 18: nobody cared (try booting with the "irqpoll" option)
[ 34.157516] CPU: 3 PID: 0 Comm: swapper/3 Not tainted 4.9.0-040900rc6-generic #201611201731
[ 34.157518] Hardware name: To Be Filled By O.E.M. To Be Filled By O.E.M./To be filled by O.E.M., BIOS 0500 05/11/2010
[ 34.157520] ffff8a4cdfd83eb8 ffffffff8f217542 ffff8a4cd6fbb200 ffff8a4cd6fbb2b4
[ 34.157524] ffff8a4cdfd83ee8 ffffffff8eee5005 ffff8a4cd6fbb200 0000000000000000
[ 34.157527] ffffffff8fd5d560 0000000000000022 ffff8a4cdfd83f20 ffffffff8eee5393
[ 34.157529] Call Trace:
[ 34.157531] <IRQ>
[ 34.157537] [<ffffffff8f217542>] dump_stack+0x63/0x81
[ 34.157540] [<ffffffff8eee5005>] __report_bad_irq+0x35/0xc0
[ 34.157542] [<ffffffff8eee5393>] note_interrupt+0x243/0x290
[ 34.157544] [<ffffffff8eee24c4>] handle_irq_event_percpu+0x54/0x80
[ 34.157546] [<ffffffff8eee252e>] handle_irq_event+0x3e/0x60
[ 34.157548] [<ffffffff8eee5a8f>] handle_fasteoi_irq+0x9f/0x150
[ 34.157551] [<ffffffff8ee3030a>] handle_irq+0x1a/0x30
[ 34.157554] [<ffffffff8f68ec5b>] do_IRQ+0x4b/0xd0
[ 34.157556] [<ffffffff8f68cd42>] common_interrupt+0x82/0x82
[ 34.157557] <EOI>
[ 34.157560] [<ffffffff8f68bc06>] ? native_safe_halt+0x6/0x10
[ 34.157562] [<ffffffff8f68b940>] default_idle+0x20/0xd0
[ 34.157565] [<ffffffff8ee3830f>] arch_cpu_idle+0xf/0x20
[ 34.157568] [<ffffffff8f68bd53>] default_idle_call+0x23/0x30
[ 34.157570] [<ffffffff8eec96b0>] cpu_startup_entry+0x1d0/0x240
[ 34.157573] [<ffffffff8ee51a81>] start_secondary+0x151/0x190
[ 34.157575] handlers:
[ 34.157577] [<ffffffff8f45ca30>] usb_hcd_irq
[ 34.157578] [<ffffffff8f45ca30>] usb_hcd_irq
[ 34.157580] [<ffffffff8f45ca30>] usb_hcd_irq
[ 34.157581] Disabling IRQ #18
Looks to me like that USB host controller driver doesn't want to handle
its interrupt.
Lemme add USB people as I have no clue here why...
--
Regards/Gruss,
Boris.
Good mailing practices for 400: avoid top-posting and trim the reply.
Hi, Clemens and Borislav.
On Nov 25 2016, Clemens Ladisch wrote:
> Rogério Brito wrote:
> > * I have never been able to boot this computer of mine without the option
> > irqpoll---otherwise, I get the nobody cared message.
>
> The "nobody cared" message indicates that there were too many interrupts
> that no driver felt responsible for, so the kernel has disabled that
> interrupt vector. The irqpoll option is a workaround to get the devices
> on that interrupt vector to work, but it's not perfect.
Ah, great to know. I don't know if this is related or not, but I read
somewhere (don't remember where) that the machine may have performance
slightly reduced when irqpoll is used.
> It's possible that most of your problems are caused by the irqpoll option.
Excellent to know.
> What IRQ is the problematic one (see the "nobody cared" message)? What
> devices are connected to it (see /proc/interrupts)?
>From the dmesg log, the interrupt is 18.
Here is part from /proc/interrupts that contains interrupt 18 *without* irqpoll:
---------------------------
CPU0 CPU1 CPU2 CPU3
0: 47 0 0 0 IO-APIC 2-edge timer
1: 0 0 0 2 IO-APIC 1-edge i8042
7: 0 0 0 0 IO-APIC 7-edge parport0
8: 0 0 0 1 IO-APIC 8-edge rtc0
9: 0 0 0 0 IO-APIC 9-fasteoi acpi
10: 0 0 0 0 IO-APIC 10-edge radeon
12: 0 0 0 4 IO-APIC 12-edge i8042
16: 0 96 4 990 IO-APIC 16-fasteoi ohci_hcd:usb3, ohci_hcd:usb4, snd_hda_intel:card0
17: 0 2457 1 140 IO-APIC 17-fasteoi ehci_hcd:usb1
18: 1 11 43 99947 IO-APIC 18-fasteoi ohci_hcd:usb5, ohci_hcd:usb6, ohci_hcd:usb7
19: 0 0 0 0 IO-APIC 19-fasteoi ehci_hcd:usb2
22: 0 22169 139 8731 IO-APIC 22-fasteoi ahci[0000:00:11.0]
25: 0 0 11 753 PCI-MSI 1048576-edge eth0
(...)
---------------------------
Here is part from /proc/interrupts that contains interrupt 18 *with* irqpoll:
---------------------------
CPU0 CPU1 CPU2 CPU3
0: 46 0 0 0 IO-APIC 2-edge timer
1: 0 0 0 2 IO-APIC 1-edge i8042
7: 0 0 0 0 IO-APIC 7-edge parport0
8: 0 0 0 1 IO-APIC 8-edge rtc0
9: 0 0 0 0 IO-APIC 9-fasteoi acpi
10: 0 0 0 0 IO-APIC 10-edge radeon
12: 0 0 0 4 IO-APIC 12-edge i8042
16: 0 103 6 983 IO-APIC 16-fasteoi ohci_hcd:usb3, ohci_hcd:usb4, snd_hda_intel:card0
17: 0 588 0 144 IO-APIC 17-fasteoi ehci_hcd:usb1
18: 0 0 0 705 IO-APIC 18-fasteoi ohci_hcd:usb5, ohci_hcd:usb6, ohci_hcd:usb7
19: 0 0 0 0 IO-APIC 19-fasteoi ehci_hcd:usb2
22: 0 18049 4 8540 IO-APIC 22-fasteoi ahci[0000:00:11.0]
25: 0 0 0 327 PCI-MSI 1048576-edge eth0
(...)
---------------------------
I'm attaching both files to this message.
> Does the problem go away when you prevent the corresponding driver(s) from
> loading?
Since the OHCI_HCD driver is built-in (as opposed to a module), I don't know
how to disable it. I can try to recompile the kernel with it as a module and
rename it as some garbage, so that it doesn't get loaded...
Thanks a lot,
--
Rogério Brito : rbrito@{ime.usp.br,gmail.com} : GPG key 4096R/BCFCAAAA
http://rb.doesntexist.org/blog : Projects : https://github.com/rbrito/
DebianQA: http://qa.debian.org/developer.php?login=rbrito%40ime.usp.br
On Fri, Nov 25, 2016 at 02:53:00PM -0200, Rogério Brito wrote:
> Here is part from /proc/interrupts that contains interrupt 18 *without* irqpoll:
>
> ---------------------------
> CPU0 CPU1 CPU2 CPU3
> 0: 47 0 0 0 IO-APIC 2-edge timer
> 1: 0 0 0 2 IO-APIC 1-edge i8042
> 7: 0 0 0 0 IO-APIC 7-edge parport0
> 8: 0 0 0 1 IO-APIC 8-edge rtc0
> 9: 0 0 0 0 IO-APIC 9-fasteoi acpi
> 10: 0 0 0 0 IO-APIC 10-edge radeon
> 12: 0 0 0 4 IO-APIC 12-edge i8042
> 16: 0 96 4 990 IO-APIC 16-fasteoi ohci_hcd:usb3, ohci_hcd:usb4, snd_hda_intel:card0
> 17: 0 2457 1 140 IO-APIC 17-fasteoi ehci_hcd:usb1
> 18: 1 11 43 99947 IO-APIC 18-fasteoi ohci_hcd:usb5, ohci_hcd:usb6, ohci_hcd:usb7
Can you connect the printer to a different port so that it doesn't use
OCHI to see if it makes any difference?
> 19: 0 0 0 0 IO-APIC 19-fasteoi ehci_hcd:usb2
> 22: 0 22169 139 8731 IO-APIC 22-fasteoi ahci[0000:00:11.0]
> 25: 0 0 11 753 PCI-MSI 1048576-edge eth0
> (...)
> ---------------------------
--
Regards/Gruss,
Boris.
Good mailing practices for 400: avoid top-posting and trim the reply.
Hi, Clemens and others.
On Nov 25 2016, Clemens Ladisch wrote:
> Rogério Brito wrote:
> > [ 130.007219] evbug: Event. Dev: input6, Type: 0, Code: 0, Value: 0
>
> The evbug module is intended for debugging; it dumps all input events
> into syslog. If you do not want these messages, do not load this module.
> (If it is loaded automatically, you have an actual bug.)
It *was* loaded automatically, and I didn't specifically asked it to be
loaded, but I'm not sure if other parts of userspace forced it to be
loaded. I will disable it, then.
Here is the relevant part of the config file:
,----[ grep -i evbug /boot/config-4.9.0-040900rc6-generic ]
| CONFIG_INPUT_EVBUG=m
`----
Thanks,
--
Rogério Brito : rbrito@{ime.usp.br,gmail.com} : GPG key 4096R/BCFCAAAA
http://rb.doesntexist.org/blog : Projects : https://github.com/rbrito/
DebianQA: http://qa.debian.org/developer.php?login=rbrito%40ime.usp.br