Groups | Search | Server Info | Keyboard shortcuts | Login | Register [http] [https] [nntp] [nntps]


Groups > linux.kernel > #1616926

[BUG] stack tracing causes: kernel/module.c:271 module_assert_mutex_or_preempt

From Steven Rostedt <rostedt@goodmis.org>
Newsgroups linux.kernel
Subject [BUG] stack tracing causes: kernel/module.c:271 module_assert_mutex_or_preempt
Date 2017-04-05 15:40 +0200
Message-ID <tsTkd-3ev-7@gated-at.bofh.it> (permalink)
Organization linux.* mail to news gateway

Show all headers | View raw


Hi Paul,

My tests are triggering the following when I have lockdep enabled and
running the stack tracer:

------------[ cut here ]------------
WARNING: CPU: 0 PID: 0 at /work/autotest/nobackup/linux-test.git/kernel/module.c:271 module_assert_mutex_or_preempt+0x4f/0x51
Modules linked in: ppdev parport_pc parport [last unloaded: trace_events_sample]
CPU: 0 PID: 0 Comm: swapper/0 Not tainted 4.11.0-rc3-test+ #48
Hardware name: MSI MS-7823/CSM-H87M-G43 (MS-7823), BIOS V1.6 02/22/2014
Call Trace:

===============================
[ ERR: suspicious RCU usage.  ]
4.11.0-rc3-test+ #48 Not tainted
-------------------------------
/work/autotest/nobackup/linux-test.git/include/linux/rcupdate.h:837 rcu_read_lock() used illegally while idle!

other info that might help us debug this:


RCU used illegally from idle CPU!
rcu_scheduler_active = 2, debug_locks = 0
RCU used illegally from extended quiescent state!
1 lock held by swapper/0/0:
 #0:  (rcu_read_lock){......}, at: [<ffffffff810ebee3>] rcu_read_lock+0x0/0x61

stack backtrace:
CPU: 0 PID: 0 Comm: swapper/0 Not tainted 4.11.0-rc3-test+ #48
Hardware name: MSI MS-7823/CSM-H87M-G43 (MS-7823), BIOS V1.6 02/22/2014
Call Trace:
 dump_stack+0x68/0x92
 __warn+0xc2/0xdd
 ? 0xffffffffa0026077
 warn_slowpath_null+0x1d/0x1f
 module_assert_mutex_or_preempt+0x4f/0x51
 __module_address+0x2a/0xac
 ? 0xffffffffa0026077
 __module_text_address+0x12/0x59
 ? 0xffffffffa0026077
 is_module_text_address+0xe/0x16
 __kernel_text_address+0x2b/0x80
 ? 0xffffffffa0026077
 unwind_get_return_address+0x50/0x5c
 __save_stack_trace+0x76/0xbf
 ? rcu_eqs_enter_common.constprop.71+0x5/0x108
 save_stack_trace+0x1b/0x1d
 check_stack+0xec/0x24a
 stack_trace_call+0x40/0x53     <<-- This is the start of the stack tracer
 0xffffffffa0026077
 ? ftrace_graph_caller+0x78/0xa8
 ? trace_hardirqs_off+0xd/0xf
 ? rcu_eqs_enter_common.constprop.71+0x5/0x108
 rcu_eqs_enter_common.constprop.71+0x5/0x108   <<-- It appears to be testing the rcu internal code
 rcu_idle_enter+0x51/0x72
 ? rcu_eqs_enter_common.constprop.71+0x5/0x108
 ? rcu_idle_enter+0x51/0x72
 do_idle+0xbb/0x1e5
 cpu_startup_entry+0x1f/0x21
 rest_init+0x127/0x12d
 start_kernel+0x3f5/0x402
 x86_64_start_reservations+0x2f/0x31
 x86_64_start_kernel+0x17f/0x192
 start_cpu+0x14/0x14
 ? start_cpu+0x14/0x14
---[ end trace eeaad31bc52457e7 ]---


Now the check_stack() function in kernel/trace/trace_stack.c has the
following:

	/*
	 * RCU may not be watching, make it see us.
	 * The stack trace code uses rcu_sched.
	 */
	rcu_irq_enter();


What I'm guessing, is that because it is tracing the internals of the
rcu code, and checking its stack, the stack trace triggered in a
location where calling rcu_irq_enter() isn't sufficient to have rcu
become watchable.

I may add code to check if rcu is indeed watching after the
rcu_irq_enter() call, and if it still isn't to simply exit out.

Thoughts?

-- Steve

Back to linux.kernel | Previous | NextNext in thread | Find similar | Unroll thread


Thread

[BUG] stack tracing causes: kernel/module.c:271  module_assert_mutex_or_preempt Steven Rostedt <rostedt@goodmis.org> - 2017-04-05 15:40 +0200
  Re: [BUG] stack tracing causes: kernel/module.c:271  module_assert_mutex_or_preempt "Paul E. McKenney" <paulmck@linux.vnet.ibm.com> - 2017-04-05 18:30 +0200
    Re: [BUG] stack tracing causes: kernel/module.c:271  module_assert_mutex_or_preempt Steven Rostedt <rostedt@goodmis.org> - 2017-04-05 18:50 +0200
      Re: [BUG] stack tracing causes: kernel/module.c:271  module_assert_mutex_or_preempt "Paul E. McKenney" <paulmck@linux.vnet.ibm.com> - 2017-04-05 20:10 +0200
        Re: [BUG] stack tracing causes: kernel/module.c:271  module_assert_mutex_or_preempt Steven Rostedt <rostedt@goodmis.org> - 2017-04-05 21:00 +0200
          Re: [BUG] stack tracing causes: kernel/module.c:271  module_assert_mutex_or_preempt "Paul E. McKenney" <paulmck@linux.vnet.ibm.com> - 2017-04-05 21:10 +0200
            Re: [BUG] stack tracing causes: kernel/module.c:271  module_assert_mutex_or_preempt Steven Rostedt <rostedt@goodmis.org> - 2017-04-05 21:30 +0200
              Re: [BUG] stack tracing causes: kernel/module.c:271  module_assert_mutex_or_preempt "Paul E. McKenney" <paulmck@linux.vnet.ibm.com> - 2017-04-05 21:40 +0200
                Re: [BUG] stack tracing causes: kernel/module.c:271  module_assert_mutex_or_preempt Steven Rostedt <rostedt@goodmis.org> - 2017-04-05 22:00 +0200
                Re: [BUG] stack tracing causes: kernel/module.c:271  module_assert_mutex_or_preempt "Paul E. McKenney" <paulmck@linux.vnet.ibm.com> - 2017-04-05 22:50 +0200
                Re: [BUG] stack tracing causes: kernel/module.c:271  module_assert_mutex_or_preempt Steven Rostedt <rostedt@goodmis.org> - 2017-04-06 03:40 +0200
                Re: [BUG] stack tracing causes: kernel/module.c:271  module_assert_mutex_or_preempt "Paul E. McKenney" <paulmck@linux.vnet.ibm.com> - 2017-04-06 06:10 +0200
        Re: [BUG] stack tracing causes: kernel/module.c:271  module_assert_mutex_or_preempt Steven Rostedt <rostedt@goodmis.org> - 2017-04-06 04:20 +0200
          Re: [BUG] stack tracing causes: kernel/module.c:271  module_assert_mutex_or_preempt "Paul E. McKenney" <paulmck@linux.vnet.ibm.com> - 2017-04-06 06:20 +0200
            Re: [BUG] stack tracing causes: kernel/module.c:271  module_assert_mutex_or_preempt Steven Rostedt <rostedt@goodmis.org> - 2017-04-06 16:20 +0200
              Re: [BUG] stack tracing causes: kernel/module.c:271  module_assert_mutex_or_preempt "Paul E. McKenney" <paulmck@linux.vnet.ibm.com> - 2017-04-06 17:10 +0200

csiph-web