From mboxrd@z Thu Jan  1 00:00:00 1970
Return-Path: <linux-kernel-owner@vger.kernel.org>
Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand
        id S1752487AbdKGBrU (ORCPT <rfc822;w@1wt.eu>);
        Mon, 6 Nov 2017 20:47:20 -0500
Received: from mga02.intel.com ([134.134.136.20]:50019 "EHLO mga02.intel.com"
        rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP
        id S1751713AbdKGBrT (ORCPT <rfc822;linux-kernel@vger.kernel.org>);
        Mon, 6 Nov 2017 20:47:19 -0500
X-ExtLoop1: 1
X-IronPort-AV: E=Sophos;i="5.44,355,1505804400"; 
   d="scan'208";a="918313033"
Date: Tue, 7 Nov 2017 09:47:15 +0800
From: Fengguang Wu <fengguang.wu@intel.com>
To: x86@kernel.org
Cc: LKML <linux-kernel@vger.kernel.org>,
        Linus Torvalds <torvalds@linux-foundation.org>,
        Yinghai Lu <yinghai@kernel.org>,
        Suresh Siddha <suresh.b.siddha@intel.com>, Ingo Molnar <mingo@elte.hu>,
        Len Brown <len.brown@intel.com>, Thomas Gleixner <tglx@linutronix.de>
Subject: [apic_ap_setup] WARNING: suspicious RCU usage
Message-ID: <20171107014715.66eojkmbaurdfqnv@wfg-t540p.sh.intel.com>
References: <20171107013821.2b34a6i6uez37stu@wfg-t540p.sh.intel.com>
MIME-Version: 1.0
Content-Type: text/plain; charset=us-ascii; format=flowed
Content-Disposition: inline
In-Reply-To: <20171107013821.2b34a6i6uez37stu@wfg-t540p.sh.intel.com>
User-Agent: NeoMutt/20170609 (1.8.3)
Sender: linux-kernel-owner@vger.kernel.org
List-ID: <linux-kernel.vger.kernel.org>
X-Mailing-List: linux-kernel@vger.kernel.org

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