pinctrl_cherryview: massive error messages (handle_bad_irq)
From: Christian Steiner
Date: Wed Oct 19 2016 - 14:38:25 EST
Hello,
since Kernel 4.8 I see a lot of the following error messages after
resuming from suspend to RAM:
> irq 117, desc: ffff88017a61e600, depth: 1, count: 0, unhandled: 0
> ->handle_irq(): ffffffff8109b613, handle_bad_irq+0x0/0x1e0
> ->irq_data.chip(): ffffffffa0020180, chv_pinctrl_exit+0x2d84/0x12 [pinctrl_cherryview]
> ->action(): (null)
> IRQ_NOPROBE set
The messages appear a few thousand times and mess up the log. Despite
the messages everything seems to work fine.
I see the messages with Kernel 4.8.2 and 4.9-rc1. The do not appear with
Kernel 4.7.8 or earlier.
I have an Acer TravelMate B116-M laptop with an Intel Pentium N3700
processor.
Here are the full log messages of a suspend to RAM and resume cycle with
Kernel 4.7.8:
> [ 22.605418] PM: Syncing filesystems ... done.
> [ 22.613640] PM: Preparing system for sleep (mem)
> [ 22.615108] Freezing user space processes ... (elapsed 0.001 seconds) done.
> [ 22.616930] Double checking all user space processes after OOM killer disable... (elapsed 0.000 seconds)
> [ 22.616956] Freezing remaining freezable tasks ... (elapsed 0.001 seconds) done.
> [ 22.618611] PM: Suspending system (mem)
> [ 22.618640] Suspending console(s) (use no_console_suspend to debug)
> [ 22.619773] sd 0:0:0:0: [sda] Synchronizing SCSI cache
> [ 22.626173] sd 0:0:0:0: [sda] Stopping disk
> [ 23.670076] PM: suspend of devices complete after 1051.008 msecs
> [ 23.691058] PM: late suspend of devices complete after 20.971 msecs
> [ 23.692104] r8169 0000:03:00.0: System wakeup enabled by ACPI
> [ 23.693087] xhci_hcd 0000:00:14.0: System wakeup enabled by ACPI
> [ 23.711687] PM: noirq suspend of devices complete after 20.624 msecs
> [ 23.711726] ACPI: Preparing to enter system sleep state S3
> [ 23.712295] ACPI : EC: EC stopped
> [ 23.712297] PM: Saving platform NVS memory
> [ 23.712306] Disabling non-boot CPUs ...
> [ 23.712590] Cannot set affinity for irq 191
> [ 23.713647] smpboot: CPU 1 is now offline
> [ 23.752643] smpboot: CPU 2 is now offline
> [ 23.802930] smpboot: CPU 3 is now offline
> [ 23.831827] ACPI: Low-level resume complete
> [ 23.831938] ACPI : EC: EC started
> [ 23.831939] PM: Restoring platform NVS memory
> [ 23.832600] Enabling non-boot CPUs ...
> [ 23.882819] x86: Booting SMP configuration:
> [ 23.882821] smpboot: Booting Node 0 Processor 1 APIC 0x2
> [ 23.885308] cache: parent cpu1 should not be sleeping
> [ 23.885757] CPU1 is up
> [ 23.932612] smpboot: Booting Node 0 Processor 2 APIC 0x4
> [ 23.935171] cache: parent cpu2 should not be sleeping
> [ 23.935674] CPU2 is up
> [ 23.982749] smpboot: Booting Node 0 Processor 3 APIC 0x6
> [ 23.985324] cache: parent cpu3 should not be sleeping
> [ 23.985840] CPU3 is up
> [ 23.986370] ACPI: Waking up from system sleep state S3
> [ 24.012307] xhci_hcd 0000:00:14.0: System wakeup disabled by ACPI
> [ 24.023417] PM: noirq resume of devices complete after 20.911 msecs
> [ 25.052523] PM: early resume of devices complete after 1029.024 msecs
> [ 25.053082] r8169 0000:03:00.0: System wakeup disabled by ACPI
> [ 25.053124] iwlwifi 0000:02:00.0: RF_KILL bit toggled to disable radio.
> [ 25.054222] rtc_cmos 00:04: System wakeup disabled by ACPI
> [ 25.055645] sd 0:0:0:0: [sda] Starting disk
> [ 25.075031] r8169 0000:03:00.0 eth0: link down
> [ 25.374179] ata1: SATA link up 6.0 Gbps (SStatus 133 SControl 300)
> [ 25.377616] ata1.00: configured for UDMA/133
> [ 26.025736] PM: resume of devices complete after 973.238 msecs
> [ 26.026109] PM: Finishing wakeup.
> [ 26.026111] Restarting tasks ... done.
> [ 27.767611] r8169 0000:03:00.0 eth0: link up
And this is how it looks with Kernel 4.8.2:
> [ 46.928231] PM: Syncing filesystems ... done.
> [ 46.930391] PM: Preparing system for sleep (mem)
> [ 46.932002] Freezing user space processes ... (elapsed 0.001 seconds) done.
> [ 46.933721] Double checking all user space processes after OOM killer disable... (elapsed 0.000 seconds)
> [ 46.933749] Freezing remaining freezable tasks ... (elapsed 0.001 seconds) done.
> [ 46.935457] PM: Suspending system (mem)
> [ 46.935486] Suspending console(s) (use no_console_suspend to debug)
> [ 46.936492] sd 0:0:0:0: [sda] Synchronizing SCSI cache
> [ 46.936598] sd 0:0:0:0: [sda] Stopping disk
> [ 48.026353] PM: suspend of devices complete after 1090.448 msecs
> [ 48.057844] PM: late suspend of devices complete after 31.480 msecs
> [ 48.059086] r8169 0000:03:00.0: System wakeup enabled by ACPI
> [ 48.059240] xhci_hcd 0000:00:14.0: System wakeup enabled by ACPI
> [ 48.117234] PM: noirq suspend of devices complete after 59.386 msecs
> [ 48.117269] ACPI: Preparing to enter system sleep state S3
> [ 48.117836] ACPI : EC: EC stopped
> [ 48.117837] PM: Saving platform NVS memory
> [ 48.117846] Disabling non-boot CPUs ...
> [ 48.118130] Cannot set affinity for irq 191
> [ 48.119186] smpboot: CPU 1 is now offline
> [ 48.179126] smpboot: CPU 2 is now offline
> [ 48.229450] smpboot: CPU 3 is now offline
> [ 48.278338] ACPI: Low-level resume complete
> [ 48.278415] ACPI : EC: EC started
> [ 48.278416] PM: Restoring platform NVS memory
> [ 48.279036] irq 117, desc: ffff88017a61e600, depth: 1, count: 0, unhandled: 0
> [ 48.279044] ->handle_irq(): ffffffff8109b613, handle_bad_irq+0x0/0x1e0
> [ 48.279052] ->irq_data.chip(): ffffffffa0020180, chv_pinctrl_exit+0x2d84/0x12 [pinctrl_cherryview]
> [ 48.279054] ->action(): (null)
> [ 48.279055] IRQ_NOPROBE set
> [ 48.279057] unexpected IRQ trap at vector 75
>
[...]
>
> [ 48.659033] irq 117, desc: ffff88017a61e600, depth: 1, count: 0, unhandled: 0
> [ 48.659037] ->handle_irq(): ffffffff8109b613, handle_bad_irq+0x0/0x1e0
> [ 48.659041] ->irq_data.chip(): ffffffffa0020180, chv_pinctrl_exit+0x2d84/0x12 [pinctrl_cherryview]
> [ 48.659042] ->action(): (null)
> [ 48.659043] IRQ_NOPROBE set
> [ 49.698698] PM: early resume of devices complete after 1089.068 msecs
> [ 49.699601] r8169 0000:03:00.0: System wakeup disabled by ACPI
> [ 49.699633] iwlwifi 0000:02:00.0: RF_KILL bit toggled to disable radio.
> [ 49.708346] sd 0:0:0:0: [sda] Starting disk
> [ 49.708581] rtc_cmos 00:04: System wakeup disabled by ACPI
> [ 49.731492] r8169 0000:03:00.0 eth0: link down
> [ 50.039718] ata1: SATA link up 6.0 Gbps (SStatus 133 SControl 300)
> [ 50.041544] ata1.00: configured for UDMA/133
> [ 50.381833] PM: resume of devices complete after 683.151 msecs
> [ 50.385539] PM: Finishing wakeup.
> [ 50.385541] Restarting tasks ... done.
Are the messages just informational or is this something serious that
should be fixed?
If you need more information or if I should test a patch, please let me
know.
Regards,
Christian