[apic_ap_setup] WARNING: suspicious RCU usage

[Fengguang Wu]

Hi,

Here is a warning in 4.14-rc8 -- it's not necessarily a new bug.

[  112.658399] smpboot: Booting Node 0 Processor 1 APIC 0x1
[  112.669928] kvm-clock: cpu 1, msr 0:3544e041, secondary cpu clock
[  112.670585] masked ExtINT on CPU#1
[[  112.671160] 
[  112.671161] =============================
[  112.671161] WARNING: suspicious RCU usage
[  112.671161] 4.14.0-rc8 #58 Not tainted
[  112.671162] -----------------------------
[0m
[  112.671164] 
] 
[  112.671165] 3 locks held by swapper/1/0:
[  112.671166]  #0:  ((console_sem).lock){-...}, at: [<ffffffffbcad859d>] up+0xa/0x35
[  112.671168]  #1:  (&p->pi_lock){-.-.}, at: [<ffffffffbcac3216>] try_to_wake_up+0x2f/0x22d
Failed to start 
[  112.671172] stack backtrace:
[  112.671173] CPU: 1 PID: 0 Comm: swapper/1 Not tainted 4.14.0-rc8 #58
[  112.671173] Call Trace:
[  112.671173]  ? dump_stack+0x79/0xab
[  112.671174]  ? select_task_rq_fair+0x1b8/0xa8a
[  112.671174]  ? try_to_wake_up+0x2f/0x22d

[  112.671175]  ? __lock_is_held+0x40/0x71
[  112.671175]  ? select_task_rq+0x58/0xa6
[  112.671176]  ? try_to_wake_up+0x123/0x22d
[  112.671176]  ? up+0x28/0x35
[  112.671176]  ? __up_console_sem+0x33/0x5a
[  112.671177]  ? console_unlock+0x2f8/0x42e
[  112.671177]  ? vprintk_emit+0x223/0x234
[  112.671178]  ? printk+0x3e/0x46
[  112.671178]  ? setup_local_APIC+0x1ca/0x212
[  112.671178]  ? apic_ap_setup+0x5/0xa
[  112.671179]  ? start_secondary+0x42/0xfd
[  112.671179]  ? secondary_startup_64+0xa5/0xa5
[  112.671180] 
[  112.671180] =============================
[  112.671180] WARNING: suspicious RCU usage
[  112.671181] 4.14.0-rc8 #58 Not tainted
[  112.671181] -----------------------------
[  112.671182] kernel/sched/fair.c:5828 suspicious rcu_dereference_check() usage!
[  112.671182] 
[  112.671183] other info that might help us debug this:
[  112.671183] 
[  112.671184] RCU used illegally from offline CPU!
[  112.671184] rcu_scheduler_active = 2, debug_locks = 1
[  112.671185] 3 locks held by swapper/1/0:
[  112.671185]  #0:  ((console_sem).lock){-...}, at: [<ffffffffbcad859d>] up+0xa/0x35
[  112.671187]  #1:  (&p->pi_lock){-.-.}, at: [<ffffffffbcac3216>] try_to_wake_up+0x2f/0x22d
[  112.671189]  #2:  (rcu_read_lock){....}, at: [<ffffffffbcac7d20>] rcu_read_lock+0x0/0x69
[  112.671190] 
[  112.671191] stack backtrace:
[  112.671191] CPU: 1 PID: 0 Comm: swapper/1 Not tainted 4.14.0-rc8 #58
[  112.671192] Call Trace:
[  112.671192]  ? dump_stack+0x79/0xab
[  112.671193]  ? select_task_rq_fair+0x3b3/0xa8a
[  112.671193]  ? try_to_wake_up+0x2f/0x22d
[  112.671194]  ? __lock_is_held+0x40/0x71
[  112.671194]  ? select_task_rq+0x58/0xa6
[  112.671195]  ? try_to_wake_up+0x123/0x22d
[  112.671195]  ? up+0x28/0x35
[  112.671195]  ? __up_console_sem+0x33/0x5a
[  112.671196]  ? console_unlock+0x2f8/0x42e
[  112.671196]  ? vprintk_emit+0x223/0x234
[  112.671197]  ? printk+0x3e/0x46
[  112.671197]  ? setup_local_APIC+0x1ca/0x212
[  112.671198]  ? apic_ap_setup+0x5/0xa
[  112.671198]  ? start_secondary+0x42/0xfd
[  112.671198]  ? secondary_startup_64+0xa5/0xa5
See 'systemctl status lkp-bootstrap.service' for details.
[  112.708409] KVM setup async PF for cpu 1
[  112.708909] kvm-stealtime: cpu 1, msr 3530c580
        Starting watchdog daemon...
[  112.912274] Unregister pv shared memory for cpu 1

/pkg/linux/x86_64-randconfig-ws0-11062157/gcc-6/39dae59d66acd86d1de24294bd2f343fd5e7a625/dmesg-quantal-intel12-12:20171106225942:x86_64-randconfig-ws0-11062157:4.14.0-rc8:64

[    1.684524] serial8250: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A
[    1.709802] serial8250: ttyS1 at I/O 0x2f8 (irq = 3, base_baud = 115200) is a 16550A
[    1.711772] console [ttyS0] disabled

Thanks,
Fengguang