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 12:34:15PM +0800, Fengguang Wu wrote:
FYI, this warning shows up in both v4.14-rc8 and v4.13:
[ 144.578809] br-lan: port 1(eth0) entered disabled state
[ 144.581360] device eth0 left promiscuous mode
[ 144.582699] br-lan: port 1(eth0) entered disabled state
[ 144.685012]
[ 144.685370] =====================================
[ 144.686093] WARNING: bad unlock balance detected!
[ 144.686816] 4.14.0-rc8 #158 Not tainted
[ 144.687420] -------------------------------------
[ 144.688132] ubus/19703 is trying to release lock (rcu_preempt_state) at:
[ 144.688911] [<c10e4348>] rcu_read_unlock_special+0x5f8/0x620
[ 144.689621] but there are no more locks to release!
[ 144.690374]
[ 144.690374] other info that might help us debug this:
[ 144.691407] 1 lock held by ubus/19703:
[ 144.692009] #0: (rcu_read_lock){....}, at: [<c2f043d0>]
sock_def_readable+0x0/0x100
[ 144.693212]
[ 144.693212] stack backtrace:
[ 144.693980] CPU: 0 PID: 19703 Comm: ubus Not tainted 4.14.0-rc8 #158
[ 144.694923] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS
1.10.2-1 04/01/2014
[ 144.696168] Call Trace:
[ 144.696632] dump_stack+0x16/0x1c
[ 144.697195] print_unlock_imbalance_bug+0xb9/0xd0
[ 144.697940] ? rcu_read_unlock_special+0x5f8/0x620
[ 144.698673] ? rcu_read_unlock_special+0x5f8/0x620
[ 144.699390] lock_release+0x1cc/0x490
[ 144.699990] ? rcu_gp_kthread_wake+0x34/0x50
[ 144.700678] ? rcu_read_unlock_special+0x5f8/0x620
[ 144.701431] rt_mutex_unlock+0x1e/0xb0
[ 144.702048] rcu_read_unlock_special+0x5f8/0x620
[ 144.702774] __rcu_read_unlock+0xa7/0xb0
[ 144.703422] sock_def_readable+0xd1/0x100
[ 144.704073] unix_stream_sendmsg+0x2d1/0x4d0
[ 144.704755] sock_sendmsg+0x2d/0x70
[ 144.705334] ___sys_sendmsg+0x390/0x3a0
[ 144.705963] ? kvm_clock_read+0x31/0x80
[ 144.706569] ? kvm_sched_clock_read+0x9/0x20
[ 144.707250] ? sched_clock+0x9/0x10
[ 144.707834] ? sched_clock_cpu+0x1a/0x1e0
[ 144.708473] ? pvclock_clocksource_read+0xd5/0x230
[ 144.709216] ? kvm_clock_read+0x31/0x80
[ 144.709850] ? kvm_sched_clock_read+0x9/0x20
[ 144.710526] ? sched_clock+0x9/0x10
[ 144.711082] ? sched_clock_cpu+0x1a/0x1e0
[ 144.711714] ? __fget_light+0xb7/0xf0
[ 144.712301] ? sockfd_lookup_light+0xd3/0x120
[ 144.713002] __sys_sendmsg+0x59/0x90
[ 144.713585] SyS_socketcall+0x9e4/0xb20
[ 144.714204] do_int80_syscall_32+0x95/0x290
[ 144.714883] entry_INT80_32+0x2f/0x2f
[ 144.715491] EIP: 0xb7f3e595
[ 144.715985] EFLAGS: 00000292 CPU: 0
[ 144.716566] EAX: ffffffda EBX: 00000010 ECX: bffff678 EDX: b7f83ff4
[ 144.717474] ESI: bffff678 EDI: bffff6c4 EBP: bffff708 ESP: bffff668
[ 144.718374] DS: 007b ES: 007b FS: 0000 GS: 0033 SS: 007b
procd: - reboot -
[ 145.174700] Unregister pv shared memory for cpu 0
Here is another one, called from unix_stream_connect():
Please press Enter to activate this console.
[ 46.373661] e1000: eth0 NIC Link is Up 1000 Mbps Full Duplex, Flow Control:
RX
[ 46.376639] 8021q: adding VLAN 0 to HW filter on device eth0
[ 46.507035]
[ 46.507329] =====================================
[ 46.507940] WARNING: bad unlock balance detected!
[ 46.508543] 4.14.0-rc8 #158 Not tainted
[ 46.509048] -------------------------------------
[ 46.509648] fw3/1185 is trying to release lock (rcu_preempt_state) at:
[ 46.510452] [<c10e4348>] rcu_read_unlock_special+0x5f8/0x620
[ 46.511147] but there are no more locks to release!
[ 46.511766]
[ 46.511766] other info that might help us debug this:
[ 46.512591] 1 lock held by fw3/1185:
[ 46.513070] #0: (rcu_read_lock){....}, at: [<c2f043d0>]
sock_def_readable+0x0/0x100
[ 46.514074]
[ 46.514074] stack backtrace:
[ 46.514684] CPU: 0 PID: 1185 Comm: fw3 Not tainted 4.14.0-rc8 #158
[ 46.515440] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS
1.10.2-1 04/01/2014
[ 46.516463] Call Trace:
[ 46.516831] dump_stack+0x16/0x1c
[ 46.517288] print_unlock_imbalance_bug+0xb9/0xd0
[ 46.517896] ? rcu_read_unlock_special+0x5f8/0x620
[ 46.518512] ? rcu_read_unlock_special+0x5f8/0x620
[ 46.519113] lock_release+0x1cc/0x490
[ 46.519604] ? rcu_read_unlock_special+0x5f8/0x620
[ 46.520208] ? _raw_spin_unlock_irqrestore+0x86/0xd0
[ 46.520840] rt_mutex_unlock+0x1e/0xb0
[ 46.521341] rcu_read_unlock_special+0x5f8/0x620
[ 46.521936] __rcu_read_unlock+0xa7/0xb0
[ 46.522460] sock_def_readable+0xd1/0x100
[ 46.522993] unix_stream_connect+0x633/0x680
[ 46.523552] SYSC_connect+0x107/0x120
[ 46.524046] SyS_socketcall+0x384/0xb20
[ 46.524562] ? SyS_fcntl64+0x103/0x2e0
[ 46.525060] do_int80_syscall_32+0x95/0x290
[ 46.525610] entry_INT80_32+0x2f/0x2f
[ 46.526099] EIP: 0xb7e97384
[ 46.526505] EFLAGS: 00000296 CPU: 0
[ 46.526977] EAX: ffffffda EBX: 00000003 ECX: bf988038 EDX: b7edd000
[ 46.527741] ESI: bf988038 EDI: bf9880e0 EBP: bf988098 ESP: bf988028
[ 46.528505] DS: 007b ES: 007b FS: 0000 GS: 0033 SS: 007b
[ 46.607747] 8021q: adding VLAN 0 to HW filter on device eth0
LKP: HOSTNAME vm-lkp-nhm-dp1-openwrt-ia32-6, MAC , kernel 4.14.0-rc8 158,
serial console /dev/ttyS0
Here is the call trace in older v4.13 kernel:
Please press Enter to activate this console.
[ 85.464260] e1000: eth0 NIC Link is Up 1000 Mbps Full Duplex, Flow Control:
RX
[ 85.470410] 8021q: adding VLAN 0 to HW filter on device eth0
[ 85.585813]
[ 85.586196] =====================================
[ 85.586870] WARNING: bad unlock balance detected!
[ 85.587555] 4.13.0 #1 Not tainted
[ 85.588098] -------------------------------------
[ 85.588792] ubus/1179 is trying to release lock (rcu_preempt_state) at:
[ 85.589707] [<c10e5840>] rcu_read_unlock_special+0x580/0x5b0
[ 85.590494] but there are no more locks to release!
[ 85.591196]
[ 85.591196] other info that might help us debug this:
[ 85.592201] 1 lock held by ubus/1179:
[ 85.592781] #0: (rcu_read_lock){......}, at: [<c2eadff0>]
sock_def_readable+0x0/0x100
[ 85.593930]
[ 85.593930] stack backtrace:
[ 85.594694] CPU: 0 PID: 1179 Comm: ubus Not tainted 4.13.0 #1
[ 85.595474] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS
1.10.2-1 04/01/2014
[ 85.596647] Call Trace:
[ 85.597091] dump_stack+0x16/0x1c
[ 85.597626] print_unlock_imbalance_bug+0xb9/0xd0
[ 85.598309] ? rcu_read_unlock_special+0x580/0x5b0
[ 85.599009] ? rcu_read_unlock_special+0x580/0x5b0
[ 85.599713] lock_release+0x1cc/0x490
[ 85.600320] ? rcu_gp_kthread_wake+0x34/0x50
[ 85.600968] ? rcu_read_unlock_special+0x580/0x5b0
[ 85.601653] rt_mutex_unlock+0x1e/0xb0
[ 85.602227] rcu_read_unlock_special+0x580/0x5b0
[ 85.602893] __rcu_read_unlock+0xa7/0xb0
[ 85.603490] sock_def_readable+0xd1/0x100
[ 85.604093] unix_stream_connect+0x633/0x680
[ 85.604724] SYSC_connect+0x107/0x120
[ 85.605290] SyS_socketcall+0x384/0xb20
[ 85.605871] ? SyS_fcntl64+0x103/0x2e0
[ 85.606446] do_int80_syscall_32+0x95/0x1b0
[ 85.607063] entry_INT80_32+0x2f/0x2f
[ 85.607639] EIP: 0xb7f21384
[ 85.608131] EFLAGS: 00000296 CPU: 0
[ 85.608678] EAX: ffffffda EBX: 00000003 ECX: bf923748 EDX: b7f67000
[ 85.609519] ESI: bf923748 EDI: bf9237f0 EBP: bf9237a8 ESP: bf923738
[ 85.610353] DS: 007b ES: 007b FS: 0000 GS: 0033 SS: 007b
[ 85.686243] 8021q: adding VLAN 0 to HW filter on device eth0
LKP: HOSTNAME vm-intel12-openwrt-i386-5, MAC , kernel 4.13.0 1, serial console
/dev/ttyS0
[ 87.726663] e1000: eth0 NIC Link is Up 1000 Mbps Full Duplex, Flow Control:
RX
[ 87.852942] 8021q: adding VLAN 0 to HW filter on device eth0
Thanks,
Fengguang
