A kernel warning when entering suspend

[tglx@linutronix.de (Thomas Gleixner)]

On Thu, 4 Apr 2019, Dongli Zhang wrote:
> 
> 
> On 04/04/2019 04:55 PM, Ming Lei wrote:
> > On Thu, Apr 04, 2019@08:23:59AM +0000, fin4478 fin4478 wrote:
> >> Hi,
> >>
> >> I do not use suspend/resume but noticed this kernel warning when testing it. This warning is present in earlier kernels too. My system works fine after resume.
> >> If there is a patch to fix this, I can test it.
> >>
> >> [   53.403033] PM: suspend entry (deep)
> >> [   53.403034] PM: Syncing filesystems ... done.
> >> [   53.404775] Freezing user space processes ... (elapsed 0.001 seconds) done.
> >> [   53.405972] OOM killer disabled.
> >> [   53.405973] Freezing remaining freezable tasks ... (elapsed 0.001 seconds) done.
> >> [   53.407036] printk: Suspending console(s) (use no_console_suspend to debug)
> >> [   53.407491] ACPI Debug:  "RRIO"
> >> [   53.407505] serial 00:03: disabled
> >> [   53.407560] r8169 0000:07:00.0 enp7s0: Link is Down
> >> [   53.415042] sd 5:0:0:0: [sda] Synchronizing SCSI cache
> >> [   53.415065] sd 5:0:0:0: [sda] Stopping disk
> >> [   53.428943] WARNING: CPU: 10 PID: 3127 at kernel/irq/chip.c:210 irq_startup+0xd6/0xe0
> > 
> > Looks the 'WARN_ON_ONCE(force)' in irq_startup() is a bit too strict.
> > 
> > irq_build_affinity_masks() doesn't guarantee that each IRQ's affinity
> > can include at least one online CPU.
> > 
> As the warning is triggered by below line 203,

Yeah, that's obvious.

> I can reproduce on purpose with qemu (and nvme) with some cpu offline. Here is
> related qemu cmdline:
> 
> -machine q35 -smp 2,maxcpus=4 \
> -device nvme,drive=nvmedrive,serial=deadbeaf1 \
> -drive file=test.img,if=none,id=nvmedrive \
> -monitor stdio \
> 
> As there are only 2 cpus online initially, line 203 may return >= nr_cpu_ids
> during suspend/resume.
> 
> 1. Boot VM with above qemu cmdline.
> 
> 2. In VM, run "echo freeze > /sys/power/state" and VM (with nvme) will suspend.
> 
> 3. Run "system_powerdown" in qemu monitor to wakeup VM.
> 
> There will be below logs:
> 
> [   50.956594] PM: suspend entry (s2idle)
> [   50.956595] PM: Syncing filesystems ... done.
> [   51.112756] Freezing user space processes ... (elapsed 0.001 seconds) done.
> [   51.113772] OOM killer disabled.
> [   51.113772] Freezing remaining freezable tasks ... (elapsed 0.001 seconds) done.
> [   51.114776] printk: Suspending console(s) (use no_console_suspend to debug)
> [   51.115549] e1000e: EEE TX LPI TIMER: 00000000
> [   51.118829] sd 0:0:0:0: [sda] Synchronizing SCSI cache
> [   51.119221] WARNING: CPU: 0 PID: 2517 at kernel/irq/chip.c:210
> irq_startup+0xdc/0xf0
> [   51.119222] Modules linked in:
> [   51.119223] CPU: 0 PID: 2517 Comm: kworker/u8:9 Not tainted 5.1.0-rc2+ #1
> [   51.119224] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS
> rel-1.12.1-0-ga5cab58e9a3f-prebuilt.qemu.org 04/01/2014
> [   51.119225] Workqueue: events_unbound async_run_entry_fn
> [   51.119227] RIP: 0010:irq_startup+0xdc/0xf0
> [   51.119228] Code: 31 f6 4c 89 ef e8 24 2d 00 00 85 c0 75 20 48 89 ee 31 d2 4c
> 89 ef e8 d3 d3 ff ff 48 89 df e8 cb fe ff ff 89 c5 e9 55 ff ff ff <0f> 0b eb b7
> 0f 0b eb b3 66 90 66 2e 0f 1f 84 00 00 00 00 00 55 53
> [   51.119229] RSP: 0018:ffffb7c6808a7c30 EFLAGS: 00010002
> [   51.119229] RAX: 0000000000000040 RBX: ffff98933701b400 RCX: 0000000000000040
> [   51.119230] RDX: 0000000000000040 RSI: ffffffff98340d60 RDI: ffff98933701b418
> [   51.119230] RBP: ffff98933701b418 R08: 0000000000000000 R09: 0000000000000000
> [   51.119231] R10: 0000000000000000 R11: ffffffff9824b1a8 R12: 0000000000000001
> [   51.119231] R13: 0000000000000001 R14: ffff989336959800 R15: ffff989336d2c900
> [   51.119232] FS:  0000000000000000(0000) GS:ffff989338200000(0000)
> knlGS:0000000000000000
> [   51.119234] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [   51.119235] CR2: 000055d6ae984288 CR3: 000000013360e000 CR4: 00000000000006f0
> [   51.119235] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
> [   51.119236] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
> [   51.119236] Call Trace:
> [   51.119244]  ? __irq_get_desc_lock+0x46/0x80
> [   51.119245]  enable_irq+0x41/0x80

Why is this enabling an interrupt which is managed and bound to an offline
CPU?

This is just wrong and the check rightfully catches this.

Thanks,

	tglx