Received-SPF: pass (google.com: domain of linux-kernel-owner@vger.kernel.org designates 2620:137:e000::1:20 as permitted sender) client-ip=2620:137:e000::1:20;
Date:   Wed, 7 Dec 2022 09:39:43 +0800
From:   Oliver Sang <oliver.sang@intel.com>
To:     "Paul E. McKenney" <paulmck@kernel.org>
CC:     <oe-lkp@lists.linux.dev>, <lkp@intel.com>,
        <linux-kernel@vger.kernel.org>
Subject: Re: [linus:master] [rcutorture]  a5c095e0e9:
 WARNING:suspicious_RCU_usage
Message-ID: <Y4/u3wO7gdqhv4K8@xsang-OptiPlex-9020>
References: <202212032149.66b0c23b-oliver.sang@intel.com>
 <20221203185654.GQ4001@paulmck-ThinkPad-P17-Gen-1>
Content-Type: text/plain; charset="us-ascii"
Content-Disposition: inline
In-Reply-To: <20221203185654.GQ4001@paulmck-ThinkPad-P17-Gen-1>
MIME-Version: 1.0
X-MS-Exchange-AntiSpam-MessageData-ChunkCount: 1
X-MS-Exchange-AntiSpam-MessageData-0: =?us-ascii?Q?jspnZmfJdk+ipJIY5R3hlRG2axZWvLlN9uoNXhyrP78UY0XjtYLoI4ruMTqB?=
 =?us-ascii?Q?B140cadTstpidUQGZgx8KnOAIGGXN8KBe99MFCCgTIotOthI8AawEW45Msk8?=
 =?us-ascii?Q?H2/Jg1J5unvWo7lGf/tEMbn1RKaAyyaWujXSWmz3imrRbiK5Z3Cph/y4fNbf?=
 =?us-ascii?Q?DVpJ3wJwWVJ7hAkyZTA2eugu5Ov1ioxoqxQO+NFJ4F33SnyqH09NITGL8Czc?=
 =?us-ascii?Q?vsF3h20rHexFMdvV4ZxI5CAfoiT6xMeRrgcAZUcLkBILICu3WCIKa9RFbECa?=
 =?us-ascii?Q?6f1VIgCpL1neL1+ZUQFVWn/3mJfGDvFIcPdOqtalWXEKq7jBAT3pjjnFy53E?=
 =?us-ascii?Q?jq3KXht+WUVUCbURhaF+uRiJt/B+h5HVsqFYhqh7v0K/gNhR4UFgkFRE4UH5?=
 =?us-ascii?Q?LEkBIFkLDfbL1+blmOuPhiuIoBKhaW3XamipS9BMUWnkB5eV7HhYwE0ZUwUA?=
 =?us-ascii?Q?AxlxYZoewfLZ15VCJc+3Zebi5ZQ3dDuNQKLhJzGP/REiQsJTBaboUjkCrI3w?=
 =?us-ascii?Q?cGUkAa4eh554DC6bsz/O65UXG9XIyg6GLB67kuLuxSE40NiSx1aRun6pVwJo?=
 =?us-ascii?Q?pOt3fkRWGnOf0gcsNaJu78aGpKPlmcy25Ofn+B0sXu7MAaST2sbk891Flo4q?=
 =?us-ascii?Q?WCxu4QRJqGDSk7i0gTPOmU0xxsnx+ddabTp2zjt0i0ZDi3glLQCGxt9DkZxT?=
 =?us-ascii?Q?tUosjkfWtTaK/z5jSZysilyC/Q96/VU425MbshWjLX7KRmLTDxdEukDHUu2b?=
 =?us-ascii?Q?3FOiTEPhmPdOaGARJN4pkqR/R4RiD40w2y9jLi755B9DbklBF+fG9mpQSUcc?=
 =?us-ascii?Q?f+YE2hu41+YxuwgsqHb04OOCG+6zkkGqLMRXPr0RKijC3eL4pshHwRudcJem?=
 =?us-ascii?Q?2QqO6HF79n8NThR2i/pXstUKvG+daETwuIVHlei+/sXutuRPHUqamlhar8cl?=
 =?us-ascii?Q?SwkdmV2gtcL9PoYBip60FJWvNhs8I6L2o8otyg82lp3Ivi6UX/j423tCcFhY?=
 =?us-ascii?Q?Dvx4kCqdehSC64OiFGIZ5F6X7vO6P0iGTjSqn575z6gIsoxx11QHrGI8970v?=
 =?us-ascii?Q?U0agFTiAgZwB5SOZkonZSm61txo5uUpLzgwkrRAeQxg3Ac5N95VtUE0HPljp?=
 =?us-ascii?Q?6wyo2ACgz/FtCDC1SFVyjCIWRy7bGNrRO7JGa8LhebhIDh18q2XCpoezeA5O?=
 =?us-ascii?Q?vRUODbPbN9mTXJCIZt+tkXvANrhYE9TFalVQ5bBy5MDevvYoJ08bn+bu6jhp?=
 =?us-ascii?Q?S0DurSmrhygUWLNMdRINC8+jOw9x88XDBjuJt+1M4sxOf0YCgu0RUZZ+FXBm?=
 =?us-ascii?Q?JnIB4+6t6WcKZCtZh5ggXA63lR6B1qZEaRgj13L0OpN5mMmv+RoRVwoKwVqM?=
 =?us-ascii?Q?sv3AfaZaOeBUwE4X9F8V8vpS+iLcxaMQ7OxNpH55P5OI1CNM2ExLZs19XXMz?=
 =?us-ascii?Q?Zk3yoHvz9NjwfR2anLz2Z66+49L2sh6t4tpLes+ePk1sRvAu5uv+QyL29Eaa?=
 =?us-ascii?Q?IiVgBcveInEWxS48dBHe/wOkrpvZGkogrb82W4Uj6Zts/3tofe2BXs7ey0Yz?=
 =?us-ascii?Q?jhHrVoTKC/7nttAJodWZ1ujrG4YasopbzDyQo3X2?=
X-MS-Exchange-CrossTenant-Network-Message-Id: 09e6b708-1825-4e15-72c2-08dad7f3ee44
X-MS-Exchange-CrossTenant-AuthSource: PH8PR11MB6779.namprd11.prod.outlook.com
X-MS-Exchange-CrossTenant-AuthAs: Internal
X-MS-Exchange-CrossTenant-OriginalArrivalTime: 07 Dec 2022 01:39:50.3490
 (UTC)
X-MS-Exchange-CrossTenant-FromEntityHeader: Hosted
X-MS-Exchange-CrossTenant-Id: 46c98d88-e344-4ed4-8496-4ed7712e255d
X-MS-Exchange-CrossTenant-MailboxType: HOSTED
X-MS-Exchange-CrossTenant-UserPrincipalName: VNMdl4+0a+i1QA/kXFRBJfzCVJNPCl9B9ucntJCMSRRJ/kjINXjfzcXXn7Bz32AWBjLRV2gI8HmKsVRHCYywog==
X-MS-Exchange-Transport-CrossTenantHeadersStamped: SA2PR11MB5082
X-OriginatorOrg: intel.com
X-Spam-Status: No, score=-2.1 required=5.0 tests=BAYES_00,DKIMWL_WL_HIGH,
        DKIM_SIGNED,DKIM_VALID,DKIM_VALID_AU,DKIM_VALID_EF,SPF_HELO_NONE,
        SPF_NONE autolearn=ham autolearn_force=no version=3.4.6
X-Spam-Checker-Version: SpamAssassin 3.4.6 (2021-04-09) on
        lindbergh.monkeyblade.net
Precedence: bulk
List-ID: <linux-kernel.vger.kernel.org>
X-Mailing-List: linux-kernel@vger.kernel.org

Hi Paul,

On Sat, Dec 03, 2022 at 10:56:54AM -0800, Paul E. McKenney wrote:
> On Sat, Dec 03, 2022 at 10:47:47PM +0800, kernel test robot wrote:
> > 
> > Greeting,
> > 
> > FYI, we noticed WARNING:suspicious_RCU_usage due to commit (built with gcc-11):
> > 
> > commit: a5c095e0e9b6fedcffd0907c84f77751128e2a34 ("rcutorture: Abstract read-lock-held checks")
> > https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git master
> > 
> > in testcase: rcutorture
> 
> This is expected behavior!

Thanks a lot for detailed guidance as below!

> 
> Your dmesg contains "busted_srcud-torture: rcu_torture_reader task started",
> which indicates that you are testing with "busted_srcud".  Searching
> for the string "busted_srcud" (with quotes) gets us this:
> 
> /* As above, but broken due to inappropriate reader extension. */
> static struct rcu_torture_ops busted_srcud_ops = {
> 	.ttype		= SRCU_FLAVOR,
> 	.init		= srcu_torture_init,
> 	.cleanup	= srcu_torture_cleanup,
> 	.readlock	= srcu_torture_read_lock,
> 	.read_delay	= rcu_read_delay,
> 	.readunlock	= srcu_torture_read_unlock,
> 	.readlock_held	= torture_srcu_read_lock_held,
> 	.get_gp_seq	= srcu_torture_completed,
> 	.deferred_free	= srcu_torture_deferred_free,
> 	.sync		= srcu_torture_synchronize,
> 	.exp_sync	= srcu_torture_synchronize_expedited,
> 	.call		= srcu_torture_call,
> 	.cb_barrier	= srcu_torture_barrier,
> 	.stats		= srcu_torture_stats,
> 	.irq_capable	= 1,
> 	.no_pi_lock	= IS_ENABLED(CONFIG_TINY_SRCU),
> 	.extendables	= RCUTORTURE_MAX_EXTEND,
> 	.name		= "busted_srcud"
> };
> 
> That comment says it all.  The point of this test is to make sure that
> rcutorture really does group differeent types of readers together
> when asked.  Since we have torture_srcu_read_lock_held(), we expect
> rcutorture to complain when the reader uses one of the non-SRCU readers,
> such as preemption being disabled.
> 
> So the complaint you got was an indication that rcutorture really will
> complain when as it should when a given RCU flavor's read-side protection
> is broken.
> 
> 							Thanx, Paul
> 
> > [  154.593443][  T500] WARNING: suspicious RCU usage
> > [  154.594126][  T500] 5.13.0-rc1-00008-ga5c095e0e9b6 #1 Not tainted
> > [  154.594990][  T500] -----------------------------
> > [  154.595665][  T500] kernel/rcu/rcutorture.c:1568 suspicious rcu_dereference_check() usage!
> > [  154.596944][  T500]
> > [  154.596944][  T500] other info that might help us debug this:
> > [  154.596944][  T500]
> > [  154.598385][  T500]
> > [  154.598385][  T500] rcu_scheduler_active = 2, debug_locks = 1
> > [  154.599595][  T500] no locks held by rcu_torture_rea/500.
> > [  154.601317][  T500]
> > [  154.601317][  T500] stack backtrace:
> > [  154.602154][  T500] CPU: 1 PID: 500 Comm: rcu_torture_rea Not tainted 5.13.0-rc1-00008-ga5c095e0e9b6 #1
> > [  154.603441][  T500] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.16.0-debian-1.16.0-4 04/01/2014
> > [  154.604909][  T500] Call Trace:
> > [ 154.605402][ T500] ? dump_stack (??:?) 
> > [ 154.606122][ T500] ? lockdep_rcu_suspicious (??:?) 
> > [ 154.606892][ T500] ? rcu_torture_one_read (rcutorture.c:?) rcutorture
> > [ 154.607813][ T500] ? rcutorture_loop_extend (rcutorture.c:?) rcutorture
> > [ 154.608764][ T500] ? __mod_timer (timer.c:?) 
> > [ 154.609578][ T500] ? do_init_timer (timer.c:?) 
> > [ 154.610282][ T500] ? rcu_torture_reader (rcutorture.c:?) rcutorture
> > [ 154.611202][ T500] ? rcu_torture_read_exit_child (rcutorture.c:?) rcutorture
> > [ 154.612204][ T500] ? __kasan_check_read (??:?) 
> > [ 154.612974][ T500] ? rcu_torture_reader (rcutorture.c:?) rcutorture
> > [ 154.613950][ T500] ? __kasan_check_read (??:?) 
> > [ 154.614673][ T500] ? test_bit (main.c:?) 
> > [ 154.615332][ T500] ? __kthread_parkme (kthread.c:?) 
> > [ 154.616059][ T500] ? kthread (kthread.c:?) 
> > [ 154.616640][ T500] ? rcu_torture_read_exit_child (rcutorture.c:?) rcutorture
> > [ 154.617642][ T500] ? kzalloc (resource.c:?) 
> > [ 154.618361][ T500] ? ret_from_fork (??:?) 
> > [  154.627467][  T483] busted_srcud-torture: Creating torture_shuffle task
> > [  154.629419][  T502] busted_srcud-torture: rcu_torture_stats task started
> > [  154.640374][  T483] busted_srcud-torture: Creating torture_stutter task
> > [  154.644728][  T504] busted_srcud-torture: torture_shuffle task started
> > [  154.645963][  T483] busted_srcud-torture: rcu_torture_fwd_prog_init: Disabled, unsupported by RCU flavor under test
> > [  154.647399][  T483] busted_srcud-torture: Creating rcu_torture_read_exit task
> > [  154.649698][  T505] busted_srcud-torture: torture_stutter task started
> > [ 154.660318][ T483] initcall rcu_torture_init+0x0/0x2b83 [rcutorture] returned 0 after 472073 usecs 
> > [  154.679808][  T507] busted_srcud-torture: rcu_torture_read_exit: Start of test
> > [  160.204160][  T507] busted_srcud-torture: rcu_torture_read_exit: End of episode
> > [  173.852307][  T507] busted_srcud-torture: rcu_torture_read_exit: Start of episode
> > 
> >