* [gcov_enable_events] WARNING: bad unlock balance detected!
@ 2017-11-07 1:52 Fengguang Wu
2017-11-07 12:29 ` Fengguang Wu
0 siblings, 1 reply; 2+ messages in thread
From: Fengguang Wu @ 2017-11-07 1:52 UTC (permalink / raw)
To: linux-kernel
Cc: Linus Torvalds, Frantisek Hrbata, Peter Oberparleiter, Masahiro Yamada
Hi,
Here is a warning in v4.14-rc8 -- it's not necessarily a new bug.
[ 29.314270] rcu-perf: rcu_perf_writer task started
[ 29.329146] audit: initializing netlink subsys (disabled)
[ 29.337989] audit: type=2000 audit(1510004207.289:1): state=initialized audit_enabled=0 res=1
[ 39.708008]
[ 39.710234] =====================================
[ 39.710234] WARNING: bad unlock balance detected!
[ 39.710234] 4.14.0-rc8 #1 Not tainted
[ 39.710234] -------------------------------------
[ 39.710234] swapper/0/1 is trying to release lock (rcu_preempt_state) at:
[ 39.710234] [<cb4992e3>] rcu_read_unlock_special+0x6e3/0x800
[ 39.710234] but there are no more locks to release!
[ 39.710234]
[ 39.710234] other info that might help us debug this:
[ 39.710234] 4 locks held by swapper/0/1:
[ 39.710234] #0: (gcov_lock){+.+.}, at: [<cb5176b3>] gcov_enable_events+0x23/0xc0
[ 39.710234] #1: (node_lock){+.+.}, at: [<cb518cef>] gcov_event+0x2f/0x7a0
[ 39.710234] #2: (&sb->s_type->i_mutex_key#3){+.+.}, at: [<cb7d645d>] start_creating+0xcd/0x240
[ 39.710234] #3: (rcu_read_lock){....}, at: [<cb6e3b20>] __d_lookup+0x0/0x520
[ 39.710234]
[ 39.710234] stack backtrace:
[ 39.710234] CPU: 1 PID: 1 Comm: swapper/0 Not tainted 4.14.0-rc8 #1
[ 39.710234] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1 04/01/2014
[ 39.710234] Call Trace:
[ 39.710234] dump_stack+0x146/0x1e6
[ 39.710234] ? rcu_read_unlock_special+0x6e3/0x800
[ 39.710234] print_unlock_imbalance_bug+0x1cc/0x1f0
[ 39.710234] ? rcu_read_unlock_special+0x6e3/0x800
[ 39.710234] lock_release+0x41b/0xa90
[ 39.710234] ? mark_held_locks+0xd7/0x120
[ 39.710234] ? rcu_read_unlock_special+0x6e3/0x800
[ 39.710234] rt_mutex_unlock+0x3f/0x170
[ 39.710234] ? _raw_spin_unlock_irqrestore+0x133/0x170
[ 39.710234] rcu_read_unlock_special+0x6e3/0x800
[ 39.710234] ? __lock_is_held+0x58/0xe0
[ 39.710234] __rcu_read_unlock+0xbc/0x180
[ 39.710234] __d_lookup+0x4de/0x520
[ 39.710234] ? __d_lookup_rcu+0x420/0x420
[ 39.710234] ? d_lookup+0x11b/0x240
[ 39.710234] ? trace_hardirqs_on_caller+0x2d2/0x430
[ 39.710234] d_lookup+0x1b7/0x240
[ 39.710234] ? lookup_dcache+0x2f/0x170
[ 39.710234] lookup_dcache+0x2f/0x170
[ 39.710234] __lookup_hash+0x2e/0x1c0
[ 39.710234] lookup_one_len+0x282/0x2a0
[ 39.710234] start_creating+0xfb/0x240
[ 39.710234] __debugfs_create_file+0xc7/0x2f0
[ 39.710234] debugfs_create_file+0x50/0x70
[ 39.710234] new_node+0x1b5/0x350
[ 39.710234] gcov_event+0x344/0x7a0
[ 39.710234] ? gcov_persist_setup+0x90/0x90
[ 39.710234] gcov_enable_events+0x57/0xc0
[ 39.710234] gcov_fs_init+0xf3/0x13d
[ 39.710234] do_one_initcall+0x113/0x2b1
[ 39.710234] ? kernel_init_freeable+0x236/0x3b4
[ 39.710234] kernel_init_freeable+0x260/0x3b4
[ 39.710234] ? rest_init+0x440/0x440
[ 39.710234] kernel_init+0x1e/0x290
[ 39.710234] ? schedule_tail_wrapper+0x9/0xc
[ 39.710234] ret_from_fork+0x19/0x24
[ 40.559851] rcu-perf: rcu_perf_writer 1 has 100 measurements
[ 40.567049] rcu-perf: rcu_perf_writer 0 has 100 measurements
[ 40.617286] Dumping ftrace buffer:
[ 40.620255] (ftrace buffer empty)
[ 40.628854] rcu-perf: Test complete
Thanks,
Fengguang
^ permalink raw reply [flat|nested] 2+ messages in thread
* Re: [gcov_enable_events] WARNING: bad unlock balance detected!
2017-11-07 1:52 [gcov_enable_events] WARNING: bad unlock balance detected! Fengguang Wu
@ 2017-11-07 12:29 ` Fengguang Wu
0 siblings, 0 replies; 2+ messages in thread
From: Fengguang Wu @ 2017-11-07 12:29 UTC (permalink / raw)
To: linux-kernel
Cc: Linus Torvalds, Frantisek Hrbata, Peter Oberparleiter,
Masahiro Yamada, Peter Zijlstra
Sorry please ignore this report -- according to Peter:
This is fixed by commit:
02a7c234e540 ("rcu: Suppress lockdep false-positive ->boost_mtx complaints")
The problem is that RCU boosting was mixing futex and !futex rt_mutex
ops.
On Tue, Nov 07, 2017 at 09:52:09AM +0800, Fengguang Wu wrote:
>Hi,
>
>Here is a warning in v4.14-rc8 -- it's not necessarily a new bug.
>
>[ 29.314270] rcu-perf: rcu_perf_writer task started
>[ 29.329146] audit: initializing netlink subsys (disabled)
>[ 29.337989] audit: type=2000 audit(1510004207.289:1): state=initialized audit_enabled=0 res=1
>[ 39.708008]
>[ 39.710234] =====================================
>[ 39.710234] WARNING: bad unlock balance detected!
>[ 39.710234] 4.14.0-rc8 #1 Not tainted
>[ 39.710234] -------------------------------------
>[ 39.710234] swapper/0/1 is trying to release lock (rcu_preempt_state) at:
>[ 39.710234] [<cb4992e3>] rcu_read_unlock_special+0x6e3/0x800
>[ 39.710234] but there are no more locks to release!
>[ 39.710234]
>[ 39.710234] other info that might help us debug this:
>[ 39.710234] 4 locks held by swapper/0/1:
>[ 39.710234] #0: (gcov_lock){+.+.}, at: [<cb5176b3>] gcov_enable_events+0x23/0xc0
>[ 39.710234] #1: (node_lock){+.+.}, at: [<cb518cef>] gcov_event+0x2f/0x7a0
>[ 39.710234] #2: (&sb->s_type->i_mutex_key#3){+.+.}, at: [<cb7d645d>] start_creating+0xcd/0x240
>[ 39.710234] #3: (rcu_read_lock){....}, at: [<cb6e3b20>] __d_lookup+0x0/0x520
>[ 39.710234]
>[ 39.710234] stack backtrace:
>[ 39.710234] CPU: 1 PID: 1 Comm: swapper/0 Not tainted 4.14.0-rc8 #1
>[ 39.710234] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1 04/01/2014
>[ 39.710234] Call Trace:
>[ 39.710234] dump_stack+0x146/0x1e6
>[ 39.710234] ? rcu_read_unlock_special+0x6e3/0x800
>[ 39.710234] print_unlock_imbalance_bug+0x1cc/0x1f0
>[ 39.710234] ? rcu_read_unlock_special+0x6e3/0x800
>[ 39.710234] lock_release+0x41b/0xa90
>[ 39.710234] ? mark_held_locks+0xd7/0x120
>[ 39.710234] ? rcu_read_unlock_special+0x6e3/0x800
>[ 39.710234] rt_mutex_unlock+0x3f/0x170
>[ 39.710234] ? _raw_spin_unlock_irqrestore+0x133/0x170
>[ 39.710234] rcu_read_unlock_special+0x6e3/0x800
>[ 39.710234] ? __lock_is_held+0x58/0xe0
>[ 39.710234] __rcu_read_unlock+0xbc/0x180
>[ 39.710234] __d_lookup+0x4de/0x520
>[ 39.710234] ? __d_lookup_rcu+0x420/0x420
>[ 39.710234] ? d_lookup+0x11b/0x240
>[ 39.710234] ? trace_hardirqs_on_caller+0x2d2/0x430
>[ 39.710234] d_lookup+0x1b7/0x240
>[ 39.710234] ? lookup_dcache+0x2f/0x170
>[ 39.710234] lookup_dcache+0x2f/0x170
>[ 39.710234] __lookup_hash+0x2e/0x1c0
>[ 39.710234] lookup_one_len+0x282/0x2a0
>[ 39.710234] start_creating+0xfb/0x240
>[ 39.710234] __debugfs_create_file+0xc7/0x2f0
>[ 39.710234] debugfs_create_file+0x50/0x70
>[ 39.710234] new_node+0x1b5/0x350
>[ 39.710234] gcov_event+0x344/0x7a0
>[ 39.710234] ? gcov_persist_setup+0x90/0x90
>[ 39.710234] gcov_enable_events+0x57/0xc0
>[ 39.710234] gcov_fs_init+0xf3/0x13d
>[ 39.710234] do_one_initcall+0x113/0x2b1
>[ 39.710234] ? kernel_init_freeable+0x236/0x3b4
>[ 39.710234] kernel_init_freeable+0x260/0x3b4
>[ 39.710234] ? rest_init+0x440/0x440
>[ 39.710234] kernel_init+0x1e/0x290
>[ 39.710234] ? schedule_tail_wrapper+0x9/0xc
>[ 39.710234] ret_from_fork+0x19/0x24
>[ 40.559851] rcu-perf: rcu_perf_writer 1 has 100 measurements
>[ 40.567049] rcu-perf: rcu_perf_writer 0 has 100 measurements
>[ 40.617286] Dumping ftrace buffer:
>[ 40.620255] (ftrace buffer empty)
>[ 40.628854] rcu-perf: Test complete
>
>Thanks,
>Fengguang
^ permalink raw reply [flat|nested] 2+ messages in thread
end of thread, other threads:[~2017-11-07 12:29 UTC | newest]
Thread overview: 2+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2017-11-07 1:52 [gcov_enable_events] WARNING: bad unlock balance detected! Fengguang Wu
2017-11-07 12:29 ` Fengguang Wu
This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.