Hello,
The following program causes BUG: bad unlock balance detected!
https://gist.githubusercontent.com/dvyukov/d0e5efefe4d7d6daed829f5c3ca26a40/raw/08d0a261fe3c987bed04fbf267e08ba04bd533ea/gistfile1.txt
On commit 5cc60aeedf315a7513f92e98314e86d515b986d1 (Dec 14).
[ BUG: bad unlock balance detected! ]
4.9.0+ #89 Not tainted
-------------------------------------
a.out/6330 is trying to release lock (&(&new->lock)->rlock) at:
[<ffffffff8316d150>] spin_unlock include/linux/spinlock.h:347 [inline]
[<ffffffff8316d150>] ipc_unlock_object ipc/util.h:175 [inline]
[<ffffffff8316d150>] sem_unlock ipc/sem.c:404 [inline]
[<ffffffff8316d150>] SYSC_semtimedop+0x22f0/0x4410 ipc/sem.c:2004
but there are no more locks to release!
other info that might help us debug this:
2 locks held by a.out/6330:
#0: (rcu_read_lock){......}, at: [<ffffffff8316c9c2>]
SYSC_semtimedop+0x1b62/0x4410 ipc/sem.c:1968
#1: (&(&sma->sem_base[i].lock)->rlock){+.+...}, at:
[<ffffffff8316d1e4>] spin_lock include/linux/spinlock.h:302 [inline]
#1: (&(&sma->sem_base[i].lock)->rlock){+.+...}, at:
[<ffffffff8316d1e4>] sem_lock ipc/sem.c:362 [inline]
#1: (&(&sma->sem_base[i].lock)->rlock){+.+...}, at:
[<ffffffff8316d1e4>] SYSC_semtimedop+0x2384/0x4410 ipc/sem.c:1980
stack backtrace:
CPU: 1 PID: 6330 Comm: a.out Not tainted 4.9.0+ #89
Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Bochs 01/01/2011
Call Trace:
__dump_stack lib/dump_stack.c:15 [inline]
dump_stack+0x2ee/0x3ef lib/dump_stack.c:51
print_unlock_imbalance_bug+0x12f/0x140 kernel/locking/lockdep.c:3391
__lock_release kernel/locking/lockdep.c:3533 [inline]
lock_release+0xa21/0xf00 kernel/locking/lockdep.c:3772
__raw_spin_unlock include/linux/spinlock_api_smp.h:152 [inline]
_raw_spin_unlock+0x1f/0x40 kernel/locking/spinlock.c:183
spin_unlock include/linux/spinlock.h:347 [inline]
ipc_unlock_object ipc/util.h:175 [inline]
sem_unlock ipc/sem.c:404 [inline]
SYSC_semtimedop+0x22f0/0x4410 ipc/sem.c:2004
SyS_semtimedop ipc/sem.c:1755 [inline]
SYSC_semop ipc/sem.c:2015 [inline]
SyS_semop+0x2b/0x40 ipc/sem.c:2012
entry_SYSCALL_64_fastpath+0x23/0xc6
RIP: 0033:0x44dc19
RSP: 002b:00007fa18086ec88 EFLAGS: 00000206 ORIG_RAX: 0000000000000041
RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 000000000044dc19
RDX: 0000000000000001 RSI: 0000000020002ff0 RDI: 0000000000008001
RBP: 0000000000000000 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000206 R12: 0000000000000000
R13: 0000000000000000 R14: 00007fa18086f9c0 R15: 00007fa18086f700
On Fri, 16 Dec 2016, Dmitry Vyukov wrote:
>[ BUG: bad unlock balance detected! ]
>4.9.0+ #89 Not tainted
Thanks for the report, I can reproduce the issue as of (which I obviously
should have tested with lockdep):
370b262c896 (ipc/sem: avoid idr tree lookup for interrupted semop)
I need to think more about it this evening, but I believe the issue to be
the potentially bogus locknum in the unlock path, as we are calling sem_lock
without updating the variable. I'll send a patch after more testing. This
fixes it for me:
diff --git a/ipc/sem.c b/ipc/sem.c
index e08b94851922..fba6139e7208 100644
--- a/ipc/sem.c
+++ b/ipc/sem.c
@@ -1977,7 +1977,7 @@ SYSCALL_DEFINE4(semtimedop, int, semid, struct sembuf __user *, tsops,
}
rcu_read_lock();
- sem_lock(sma, sops, nsops);
+ sem_lock(sma, sops, nsops);
if (!ipc_valid_object(&sma->sem_perm))
goto out_unlock_free;
Thanks,
Davidlohr
On Sun, 18 Dec 2016, Bueso wrote:
>On Fri, 16 Dec 2016, Dmitry Vyukov wrote:
>
>>[ BUG: bad unlock balance detected! ]
>>4.9.0+ #89 Not tainted
>
>Thanks for the report, I can reproduce the issue as of (which I obviously
>should have tested with lockdep):
>
>370b262c896 (ipc/sem: avoid idr tree lookup for interrupted semop)
>
>I need to think more about it this evening, but I believe the issue to be
>the potentially bogus locknum in the unlock path, as we are calling sem_lock
>without updating the variable. I'll send a patch after more testing. This
>fixes it for me:
>
>diff --git a/ipc/sem.c b/ipc/sem.c
>index e08b94851922..fba6139e7208 100644
>--- a/ipc/sem.c
>+++ b/ipc/sem.c
>@@ -1977,7 +1977,7 @@ SYSCALL_DEFINE4(semtimedop, int, semid, struct sembuf __user *, tsops,
> }
>
> rcu_read_lock();
>- sem_lock(sma, sops, nsops);
>+ sem_lock(sma, sops, nsops);
*sigh*, that would be:
locknum = sem_lock(sma, sops, nsops);
On 12/18/2016 05:29 PM, Davidlohr Bueso wrote:
> On Sun, 18 Dec 2016, Bueso wrote:
>
>> On Fri, 16 Dec 2016, Dmitry Vyukov wrote:
>>
>>> [ BUG: bad unlock balance detected! ]
>>> 4.9.0+ #89 Not tainted
>>
>> Thanks for the report, I can reproduce the issue as of (which I
>> obviously
>> should have tested with lockdep):
>>
>> 370b262c896 (ipc/sem: avoid idr tree lookup for interrupted semop)
>>
>> I need to think more about it this evening, but I believe the issue
>> to be
>> the potentially bogus locknum in the unlock path, as we are calling
>> sem_lock
>> without updating the variable. I'll send a patch after more testing.
>> This
>> fixes it for me:
>>
>> diff --git a/ipc/sem.c b/ipc/sem.c
>> index e08b94851922..fba6139e7208 100644
>> --- a/ipc/sem.c
>> +++ b/ipc/sem.c
>> @@ -1977,7 +1977,7 @@ SYSCALL_DEFINE4(semtimedop, int, semid, struct
>> sembuf __user *, tsops,
>> }
>>
>> rcu_read_lock();
>> - sem_lock(sma, sops, nsops);
>> + sem_lock(sma, sops, nsops);
>
> *sigh*, that would be:
> locknum = sem_lock(sma, sops, nsops);
Yes, I can confirm that this fixes the issue.
Reproducing is simple:
- task A: single semop semop(), sleeps
- task B: multi semop semop(), sleeps
- task A woken up by signal/timeout
I'll send a patch.
--
Manfred
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(-)
diff --git a/ipc/sem.c b/ipc/sem.c
index e08b948..3ec5742 100644
--- a/ipc/sem.c
+++ b/ipc/sem.c
@@ -1977,7 +1977,7 @@ SYSCALL_DEFINE4(semtimedop, int, semid, struct sembuf __user *, tsops,
}
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;
--
2.7.4
Nit: the title is a bit unclear. How about:
ipc/sem.: fix semop() locking imbalance
Otherwise, Ack.
Thanks,
Davidlohr
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, and it is unlocked with sem_unlock().
The call at the syscall return locks the global spinlock.
Because locknum is not updated, the following sem_unlock() call
unlocks the per-semaphore spinlock, which is actually not locked.
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]
---
Patch V2:
- subject line updated
- documentation slightly updated
ipc/sem.c | 2 +-
1 file changed, 1 insertion(+), 1 deletion(-)
diff --git a/ipc/sem.c b/ipc/sem.c
index e08b948..3ec5742 100644
--- a/ipc/sem.c
+++ b/ipc/sem.c
@@ -1977,7 +1977,7 @@ SYSCALL_DEFINE4(semtimedop, int, semid, struct sembuf __user *, tsops,
}
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;
--
2.7.4