From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1752473AbbJTQVK (ORCPT ); Tue, 20 Oct 2015 12:21:10 -0400 Received: from smtprelay0180.hostedemail.com ([216.40.44.180]:45667 "EHLO smtprelay.hostedemail.com" rhost-flags-OK-OK-OK-FAIL) by vger.kernel.org with ESMTP id S1751697AbbJTQVG (ORCPT ); Tue, 20 Oct 2015 12:21:06 -0400 X-Session-Marker: 726F737465647440676F6F646D69732E6F7267 X-Spam-Summary: 2,0,0,,d41d8cd98f00b204,rostedt@goodmis.org,:::::::,RULES_HIT:2:41:69:355:379:541:800:960:973:988:989:1260:1277:1311:1313:1314:1345:1437:1515:1516:1518:1535:1593:1594:1605:1730:1747:1777:1792:2393:2553:2559:2562:2897:3138:3139:3140:3141:3142:3865:3867:3868:3870:3871:3872:3874:4049:4118:4321:4401:5007:6261:7901:8660:9163:10004:10848:11026:11232:11473:11658:11914:12043:12296:12438:12517:12519:12555:12679:12740:13148:13161:13229:13230:14096:14097:14394:21080,0,RBL:none,CacheIP:none,Bayesian:0.5,0.5,0.5,Netcheck:none,DomainCache:0,MSF:not bulk,SPF:fn,MSBL:0,DNSBL:none,Custom_rules:0:0:0 X-HE-Tag: waste79_9579d74f6f14 X-Filterd-Recvd-Size: 7541 Date: Tue, 20 Oct 2015 12:21:03 -0400 From: Steven Rostedt To: Peter Zijlstra Cc: "Paul E. McKenney" , LKML , Rusty Russell Subject: [PATCH] module: Prevent recursion bug caused by module RCU check Message-ID: <20151020122103.66ab250a@gandalf.local.home> X-Mailer: Claws Mail 3.12.0 (GTK+ 2.24.28; x86_64-pc-linux-gnu) MIME-Version: 1.0 Content-Type: text/plain; charset=US-ASCII Content-Transfer-Encoding: 7bit Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org The stack tracer triggered the assert in module_assert_mutex_or_preempt(), which checks that rcu_sched is used as protection, as __module_address() is protect with a synchronize_sched(). The problem with this, is that the WARN_ON() triggers a stack dump which also calls __module_address() and triggers the same warning. All I had to debug this was the following over and over. ------------[ cut here ]------------ WARNING: CPU: 5 PID: 0 at /home/rostedt/work/git/linux-trace.git/kernel/module.c:291 module_assert_mutex_or_preempt+0xa0/0xb0() Modules linked in: be2iscsi iscsi_boot_sysfs bnx2i CPU: 5 PID: 0 Comm: swapper/5 Not tainted 4.2.0-test+ #138 Hardware name: Hewlett-Packard HP Compaq Pro 6300 SFF/339A, BIOS K01 v02.05 05/07/2012 ffff88011945ba78 ffff88011945ba78 ffffffff8184d08f 0000000000000000 0000000000000000 ffff88011945bab8 ffffffff810ac1b7 ffff88011945baa8 0000000000000001 ffffffffa0080077 ffffffff81a04410 0000000000000000 Call Trace: [] dump_stack+0x4f/0xa2 [] warn_slowpath_common+0x97/0xe0 ------------[ cut here ]------------ WARNING: CPU: 5 PID: 0 at /home/rostedt/work/git/linux-trace.git/kernel/module.c:291 module_assert_mutex_or_preempt+0xa0/0xb0() Modules linked in: be2iscsi iscsi_boot_sysfs bnx2i CPU: 5 PID: 0 Comm: swapper/5 Not tainted 4.2.0-test+ #138 Hardware name: Hewlett-Packard HP Compaq Pro 6300 SFF/339A, BIOS K01 v02.05 05/07/2012 ffff88011945b768 ffff88011945b768 ffffffff8184d08f 0000000000000000 0000000000000000 ffff88011945b7a8 ffffffff810ac1b7 ffff88011945b798 0000000000000001 ffffffffa0080077 ffffffff81a02e10 0000000000000000 Call Trace: [] dump_stack+0x4f/0xa2 [] warn_slowpath_common+0x97/0xe0 ------------[ cut here ]------------ WARNING: CPU: 5 PID: 0 at /home/rostedt/work/git/linux-trace.git/kernel/module.c:291 module_assert_mutex_or_preempt+0xa0/0xb0() Modules linked in: be2iscsi iscsi_boot_sysfs bnx2i CPU: 5 PID: 0 Comm: swapper/5 Not tainted 4.2.0-test+ #138 Hardware name: Hewlett-Packard HP Compaq Pro 6300 SFF/339A, BIOS K01 v02.05 05/07/2012 ffff88011945b458 ffff88011945b458 ffffffff8184d08f 0000000000000000 0000000000000000 ffff88011945b498 ffffffff810ac1b7 ffff88011945b488 0000000000000001 ffffffffa0080077 ffffffff81a02e10 0000000000000000 I first tried to switch the WARN_ON() to a WARN_ON_ONCE() but that didn't help because the flag within WARN_ON_ONCE() is set after the stack dump, which means that it didn't solve the issue. I just decided to open code the "once" logic, and now I get: ------------[ cut here ]------------ WARNING: CPU: 0 PID: 0 at /home/rostedt/work/git/linux-trace.git/kernel/module.c:304 module_assert_mutex_or_preempt+0x84/0xa0() Modules linked in: be2iscsi iscsi_boot_sysfs bnx2i CPU: 0 PID: 0 Comm: swapper/0 Not tainted 4.3.0-rc6-test+ #185 Hardware name: Hewlett-Packard HP Compaq Pro 6300 SFF/339A, BIOS K01 v02.05 05/07/2012 ffffffff81e03a48 ffffffff81e03a48 ffffffff81445d3f 0000000000000000 0000000000000000 ffffffff81e03a88 ffffffff810ae407 ffffffff81e03a78 0000000000000000 ffffffffa008b077 ffffffff81a04550 0000000000000000 Call Trace: [] dump_stack+0x4f/0xb0 [] warn_slowpath_common+0x97/0xe0 [] ? 0xffffffffa008b077 [] ? 0xffffffffa008b077 [] warn_slowpath_null+0x1a/0x20 [] module_assert_mutex_or_preempt+0x84/0xa0 [] ? __module_address+0x38/0x220 [] ? 0xffffffffa008b077 [] __module_address+0x38/0x220 [] ? __module_address+0x5/0x220 [] ? 0xffffffffa008b077 [] ? __module_text_address+0x5/0x70 [] ? 0xffffffffa008b077 [] ? 0xffffffffa008b077 [] __module_text_address+0x16/0x70 [] ? is_module_text_address+0x21/0x80 [] ? 0xffffffffa008b077 [] is_module_text_address+0x21/0x80 [] ? 0xffffffffa008b077 [] __kernel_text_address+0x6d/0xa0 [] print_context_stack+0x73/0x120 [] dump_trace+0xcc/0x330 [] ? save_stack_trace+0x5/0x50 [] ? tlbflush_read_file+0x60/0x60 [] save_stack_trace+0x2f/0x50 [] ? stack_trace_call+0x16f/0x3b0 [] stack_trace_call+0x16f/0x3b0 [] ? nr_iowait_cpu+0x30/0x30 [] ? cpuidle_enter_state+0x62/0x3e0 [] 0xffffffffa008b077 [] ? cpuidle_enter_state+0x62/0x3e0 [] ? leave_mm+0x5/0x150 [] ? check_preemption_disabled+0x4c/0x120 [] leave_mm+0x5/0x150 [] intel_idle+0xff/0x170 [] ? leave_mm+0x5/0x150 [] ? intel_idle+0xff/0x170 [] cpuidle_enter_state+0x77/0x3e0 [] cpuidle_enter+0x17/0x20 [] cpu_startup_entry+0x540/0x560 [] rest_init+0x13c/0x150 [] ? rest_init+0x5/0x150 [] ? ftrace_init+0xc8/0x15b [] start_kernel+0x4ec/0x4f9 [] ? set_init_arg+0x57/0x57 [] ? early_idt_handler_array+0x120/0x120 [] x86_64_start_reservations+0x2a/0x2c [] x86_64_start_kernel+0x137/0x146 ---[ end trace ea6335cd0fe6994e ]--- Which would have helped me tremendously in solving the original bug. Signed-off-by: Steven Rostedt --- diff --git a/kernel/module.c b/kernel/module.c index b86b7bf1be38..d9f9be4a74e9 100644 --- a/kernel/module.c +++ b/kernel/module.c @@ -284,11 +284,25 @@ static void module_assert_mutex(void) static void module_assert_mutex_or_preempt(void) { #ifdef CONFIG_LOCKDEP + static int once; + if (unlikely(!debug_locks)) return; - WARN_ON(!rcu_read_lock_sched_held() && - !lockdep_is_held(&module_mutex)); + /* + * Would be nice to use WARN_ON_ONCE(), but the warning + * that causes a stack trace may call __module_address() + * which may call here, and we trigger the warning again, + * before the WARN_ON_ONCE() updates its flag. + * To prevent the recursion, we need to open code the + * once logic. + */ + if (!once && + unlikely(!rcu_read_lock_sched_held() && + !lockdep_is_held(&module_mutex))) { + once++; + WARN_ON(1); + } #endif }