Re: [copy_namespaces] WARNING: bad unlock balance detected!

From: Fengguang Wu
Date: Tue Nov 07 2017 - 07:30:08 EST


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:59:01AM +0800, Fengguang Wu wrote:
Hi,

Here is a warning in v4.14-rc8 -- it's not necessarily a new bug.

[ 266.395343] rcu-torture: rcu_torture_fakewriter task started
[ 266.396862] rcu-torture: Creating rcu_torture_reader task
[ 266.416970] rcu-torture: Creating rcu_torture_stats task
[ 266.458705]
[ 266.459151] =====================================
[ 266.459806] WARNING: bad unlock balance detected!
[ 266.462394] 4.14.0-rc8 #166 Not tainted
[ 266.462394] -------------------------------------
[ 266.462394] kthreadd/2 is trying to release lock (rcu_preempt_state) at:
[ 266.462394] [<810a96e7>] rcu_read_unlock_special+0x267/0x2d0
[ 266.462394] but there are no more locks to release!
[ 266.462394]
[ 266.462394] other info that might help us debug this:
[ 266.462394] 1 lock held by kthreadd/2:
[ 266.462394] #0: (rcu_read_lock){....}, at: [<810606f0>] copy_namespaces+0x0/0x180
[ 266.462394]
[ 266.462394] stack backtrace:
[ 266.462394] CPU: 0 PID: 2 Comm: kthreadd Not tainted 4.14.0-rc8 #166
[ 266.462394] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1 04/01/2014
[ 266.462394] Call Trace:
[ 266.462394] ? dump_stack+0x74/0xab
[ 266.462394] ? rcu_read_unlock_special+0x267/0x2d0
[ 266.462394] ? print_unlock_imbalance_bug+0xb4/0xc0
[ 266.462394] ? rcu_read_unlock_special+0x267/0x2d0
[ 266.462394] ? lock_release+0x39b/0x3e0
[ 266.462394] ? rt_mutex_unlock+0x18/0x80
[ 266.462394] ? rcu_read_unlock_special+0x267/0x2d0
[ 266.462394] ? __rcu_read_unlock+0x3b/0x60
[ 266.462394] ? copy_namespaces+0xf5/0x180
[ 266.462394] ? copy_process+0x15f0/0x1670
[ 266.462394] ? kthread_stop+0x50/0x50
[ 266.462394] ? kthreadd+0xe5/0x140
[ 266.462394] ? sched_clock+0x9/0x10
[ 266.462394] ? kthreadd+0xe5/0x140
[ 266.462394] ? sched_clock_local+0x1d/0x130
[ 266.462394] ? kthread_stop+0x50/0x50
[ 266.462394] ? _do_fork+0x76/0x480
[ 266.462394] ? finish_task_switch+0x145/0x1c0
[ 266.462394] ? find_held_lock+0x22/0x90
[ 266.462394] ? kthread_stop+0x50/0x50
[ 266.462394] ? kernel_thread+0x19/0x20
[ 266.462394] ? kthreadd+0xf6/0x140
[ 266.462394] ? kthread_create_on_cpu+0x80/0x80
[ 266.462394] ? ret_from_fork+0x19/0x24
[ 266.537631] rcu-torture: rcu_torture_reader task started
[ 266.541600] rcu-torture: Creating torture_shuffle task
[ 266.544634] rcu-torture: rcu_torture_stats task started
[ 266.548208] rcu-torture: Creating torture_stutter task
[ 266.552156] rcu-torture: torture_shuffle task started

Thanks,
Fengguang