This is a new one for me..
=====================================
[ BUG: bad unlock balance detected! ]
4.10.0-rc1-think+ #8 Not tainted
-------------------------------------
trinity-c47/31138 is trying to release lock (
[CONT START] &(&new->lock)->rlock
[CONT START] ) at:
[<ffffffff8136627f>] SYSC_semtimedop+0x97f/0x11d0
but there are no more locks to release!
\x0aother info that might help us debug this:
2 locks held by trinity-c47/31138:
#0:
[CONT START] (
[CONT START] rcu_read_lock
[CONT START] ){......}
[CONT START] , at: [<ffffffff813660c3>] SYSC_semtimedop+0x7c3/0x11d0
#1:
[CONT START] (
[CONT START] &(&sma->sem_base[i].lock)->rlock
[CONT START] ){......}
[CONT START] , at: [<ffffffff813662ce>] SYSC_semtimedop+0x9ce/0x11d0
\x0astack backtrace:
CPU: 0 PID: 31138 Comm: trinity-c47 Not tainted 4.10.0-rc1-think+ #8
Call Trace:
dump_stack+0x4f/0x73
? SYSC_semtimedop+0x97f/0x11d0
print_unlock_imbalance_bug+0xd8/0xe0
? SYSC_semtimedop+0x97f/0x11d0
lock_release+0x391/0x5d0
? get_lock_stats+0x19/0x50
_raw_spin_unlock+0x1f/0x50
SYSC_semtimedop+0x97f/0x11d0
? SYSC_semtimedop+0x7c3/0x11d0
? ring_buffer_lock_reserve+0x156/0x430
? do_syscall_64+0x61/0x170
? SyS_semtimedop+0x10/0x10
? ring_buffer_unlock_commit+0x26/0xd0
? trace_function+0xb8/0xf0
? SyS_semtimedop+0x10/0x10
? do_syscall_64+0x61/0x170
? function_trace_call+0x13c/0x190
? 0xffffffffa0240077
? __context_tracking_exit.part.5+0x82/0x150
? SyS_semop+0x5/0x20
? __this_cpu_preempt_check+0x13/0x20
SyS_semop+0x10/0x20
do_syscall_64+0x61/0x170
entry_SYSCALL64_slow_path+0x25/0x25
RIP: 0033:0x7f9e94cfc119
RSP: 002b:00007fffc355d498 EFLAGS: 00000246
[CONT START] ORIG_RAX: 0000000000000041
RAX: ffffffffffffffda RBX: 0000000000000041 RCX: 00007f9e94cfc119
RDX: 0000000000000001 RSI: 0000000000000001 RDI: 0000000000000000
RBP: 00007f9e95281000 R08: 00000000000000b9 R09: a5a5a5a5a5a5a5a5
R10: ffffefff00000000 R11: 0000000000000246 R12: 0000000000000002
R13: 00007f9e95281048 R14: 00007f9e953d1ad8 R15: 00007f9e95281000
On Thu, 2016-12-29 at 21:47 -0500, Dave Jones wrote:
> This is a new one for me..
>
> =====================================
> [ BUG: bad unlock balance detected! ]
> 4.10.0-rc1-think+ #8 Not tainted
> -------------------------------------
> trinity-c47/31138 is trying to release lock (
> [CONT START] &(&new->lock)->rlock
> [CONT START] ) at:
> [<ffffffff8136627f>] SYSC_semtimedop+0x97f/0x11d0
> but there are no more locks to release!
This?
From: Manfred Spraul <[email protected]>
Subject: [PATCH] ipc/sem.c: fix semop()/semop() locking failure
Date: Sun, 18 Dec 2016 19:38:45 +0100
Based on the syzcaller test case from dvyukov:
https://gist.githubusercontent.com/dvyukov/d0e5efefe4d7d6daed829f5c3ca26a40/raw/08d0a261fe3c987bed04fbf267e08ba04bd533ea/gistfile1.txt
The slow (i.e.: failure to acquire) syscall exit from semtimedop()
incorrectly assumed that the the same lock is acquired as it was
at the initial syscall entry.
This is wrong:
- thread A: single semop semop(), sleeps
- thread B: multi semop semop(), sleeps
- thread A: woken up by signal/timeout
With this sequence, the initial sem_lock() call locks the
per-semaphore spinlock, the call at the syscall return locks
the global spinlock.
The fix is trivial: Use the return value from sem_lock.
Reported-by: [email protected]
Signed-off-by: Manfred Spraul <[email protected]>
Fixes: 370b262c896e ("ipc/sem: avoid idr tree lookup for interrupted semop")
Cc: [email protected]
---
ipc/sem.c | 2 +-
1 file changed, 1 insertion(+), 1 deletion(-)
--- a/ipc/sem.c
+++ b/ipc/sem.c
@@ -1977,7 +1977,7 @@ SYSCALL_DEFINE4(semtimedop, int, semid,
}
rcu_read_lock();
- sem_lock(sma, sops, nsops);
+ locknum = sem_lock(sma, sops, nsops);
if (!ipc_valid_object(&sma->sem_perm))
goto out_unlock_free;