Re: Bug: "bad unlock balance detected" 2.6.27-rc3-next-20080820

Re: Bug: "bad unlock balance detected" 2.6.27-rc3-next-20080820

[Vegard Nossum]

[-- Attachment #1: Type: text/plain, Size: 2671 bytes --]

On Thu, Aug 21, 2008 at 9:04 AM, jay kumar <jaykumarks@gmail.com> wrote:
> While testing 2.6.27-rc3-next-20080820 ,  i observed this    "BUG:bad
> unlock balance detected" during boot time
>
> commit 765d4840cc9cca98c0cc4ff4764608780c3265f6
> Author: Stephen Rothwell <sfr@canb.auug.org.au>
> Date:   Wed Aug 20 18:59:47 2008 +1000
>
>
> Bug info:
>
> [    0.140173] =====================================
> [    0.145977] [ BUG: bad unlock balance detected! ]
> [    0.145977] -------------------------------------
> [    0.145977] khelper/12 is trying to release lock (&p->cred_exec_mutex) at:
> [    0.146977] [<c05c624f>] mutex_unlock+0xd/0xf
> [    0.146977] but there are no more locks to release!
> [    0.146977]
> [    0.146977] other info that might help us debug this:
> [    0.146977] no locks held by khelper/12.
> [    0.146977]
> [    0.146977] stack backtrace:
> [    0.146977] Pid: 12, comm: khelper Not tainted 2.6.27-rc3-next-20080820 #13
> [    0.146977]  [<c05c624f>] ? mutex_unlock+0xd/0xf
> [    0.146977]  [<c0242944>] print_unlock_inbalance_bug+0xa5/0xb2
> [    0.146977]  [<c05c624f>] ? mutex_unlock+0xd/0xf
> [    0.146977]  [<c0245cd7>] lock_release+0x8f/0x186
> [    0.146977]  [<c05c61f0>] __mutex_unlock_slowpath+0x9b/0xed
> [    0.146977]  [<c05c624f>] mutex_unlock+0xd/0xf
> [    0.146977]  [<c029506f>] free_bprm+0x24/0x39
> [    0.146977]  [<c029644e>] do_execve+0x1e5/0x1fb
> [    0.146977]  [<c0202156>] sys_execve+0x2e/0x51
> [    0.146977]  [<c0203a72>] syscall_call+0x7/0xb
> [    0.146977]  [<c0206654>] ? kernel_execve+0x1c/0x21
> [    0.146977]  [<c023383c>] ? ____call_usermodehelper+0x0/0x129
> [    0.146977]  [<c023395b>] ? ____call_usermodehelper+0x11f/0x129
> [    0.146977]  [<c023383c>] ? ____call_usermodehelper+0x0/0x129
> [    0.146977]  [<c020466b>] ? kernel_thread_helper+0x7/0x10
> [    0.146977]  =======================

(config clipped)

Hi,

Thanks for the report. The error comes from

commit d9a939fb80ef390b78b3c801f668bd1e35ebc970
Author: David Howells <dhowells@redhat.com>
Date:   Thu Aug 7 20:02:20 2008 +1000

    CRED: Make execve() take advantage of copy-on-write credentials

(Added to Cc. I guess it's also nice to Cc linux-next on errors in -next code.)

I couldn't reproduce your original failure, but I've attempted to fix
it by reordering the mutex unlock and bprm free and removing the
extraneous unlock (see attached patch; it boots for me without
errors).


Vegard

-- 
"The animistic metaphor of the bug that maliciously sneaked in while
the programmer was not looking is intellectually dishonest as it
disguises that the error is the programmer's own creation."
	-- E. W. Dijkstra, EWD1036

[-- Attachment #2: fix-execve.patch --]
[-- Type: application/octet-stream, Size: 1505 bytes --]

diff --git a/fs/exec.c b/fs/exec.c
index 4b31a72..58ddc95 100644
--- a/fs/exec.c
+++ b/fs/exec.c
@@ -1278,7 +1278,6 @@ void free_bprm(struct linux_binprm *bprm)
 {
 	free_arg_pages(bprm);
 	if (bprm->cred) {
-		mutex_unlock(&current->cred_exec_mutex);
 		abort_creds(bprm->cred);
 	}
 	kfree(bprm);
@@ -1301,25 +1300,25 @@ int do_execve(char * filename,
 	if (retval)
 		goto out_ret;
 
+	retval = mutex_lock_interruptible(&current->cred_exec_mutex);
+	if (retval < 0)
+		goto out_files;
+
 	retval = -ENOMEM;
 	bprm = kzalloc(sizeof(*bprm), GFP_KERNEL);
 	if (!bprm)
-		goto out_files;
-
-	retval = mutex_lock_interruptible(&current->cred_exec_mutex);
-	if (retval < 0)
-		goto out_free;
+		goto out_unlock;
 
 	retval = -ENOMEM;
 	bprm->cred = prepare_exec_creds();
 	if (!bprm->cred)
-		goto out_unlock;
+		goto out_free;
 	check_unsafe_exec(bprm);
 
 	file = open_exec(filename);
 	retval = PTR_ERR(file);
 	if (IS_ERR(file))
-		goto out_unlock;
+		goto out_free;
 
 	sched_exec();
 
@@ -1362,6 +1361,7 @@ int do_execve(char * filename,
 		/* execve success */
 		acct_update_integrals(current);
 		free_bprm(bprm);
+		mutex_unlock(&current->cred_exec_mutex);
 		if (displaced)
 			put_files_struct(displaced);
 		return retval;
@@ -1377,12 +1377,12 @@ out_file:
 		fput(bprm->file);
 	}
 
-out_unlock:
-	mutex_unlock(&current->cred_exec_mutex);
-
 out_free:
 	free_bprm(bprm);
 
+out_unlock:
+	mutex_unlock(&current->cred_exec_mutex);
+
 out_files:
 	if (displaced)
 		reset_files_struct(displaced);

Re: Bug: "bad unlock balance detected" 2.6.27-rc3-next-20080820

[Vegard Nossum]

On Thu, Aug 21, 2008 at 10:10 AM, Vegard Nossum <vegard.nossum@gmail.com> wrote:
> On Thu, Aug 21, 2008 at 9:04 AM, jay kumar <jaykumarks@gmail.com> wrote:
>> While testing 2.6.27-rc3-next-20080820 ,  i observed this    "BUG:bad
>> unlock balance detected" during boot time
>>
> Thanks for the report. The error comes from
>
> commit d9a939fb80ef390b78b3c801f668bd1e35ebc970
> Author: David Howells <dhowells@redhat.com>
> Date:   Thu Aug 7 20:02:20 2008 +1000
>
>    CRED: Make execve() take advantage of copy-on-write credentials
>
> (Added to Cc. I guess it's also nice to Cc linux-next on errors in -next code.)
>
> I couldn't reproduce your original failure, but I've attempted to fix
> it by reordering the mutex unlock and bprm free and removing the
> extraneous unlock (see attached patch; it boots for me without
> errors).

Actually, I was able to reproduce the original issue after all. And
the patch fixed it for me. Please review :-)


Vegard

-- 
"The animistic metaphor of the bug that maliciously sneaked in while
the programmer was not looking is intellectually dishonest as it
disguises that the error is the programmer's own creation."
	-- E. W. Dijkstra, EWD1036

Re: Bug: "bad unlock balance detected" 2.6.27-rc3-next-20080820

[Kamalesh Babulal]

Vegard Nossum wrote:
> On Thu, Aug 21, 2008 at 9:04 AM, jay kumar <jaykumarks@gmail.com> wrote:
>> While testing 2.6.27-rc3-next-20080820 ,  i observed this    "BUG:bad
>> unlock balance detected" during boot time
>>
>> commit 765d4840cc9cca98c0cc4ff4764608780c3265f6
>> Author: Stephen Rothwell <sfr@canb.auug.org.au>
>> Date:   Wed Aug 20 18:59:47 2008 +1000
>>
>>
>> Bug info:
>>
>> [    0.140173] =====================================
>> [    0.145977] [ BUG: bad unlock balance detected! ]
>> [    0.145977] -------------------------------------
>> [    0.145977] khelper/12 is trying to release lock (&p->cred_exec_mutex) at:
>> [    0.146977] [<c05c624f>] mutex_unlock+0xd/0xf
>> [    0.146977] but there are no more locks to release!
>> [    0.146977]
>> [    0.146977] other info that might help us debug this:
>> [    0.146977] no locks held by khelper/12.
>> [    0.146977]
>> [    0.146977] stack backtrace:
>> [    0.146977] Pid: 12, comm: khelper Not tainted 2.6.27-rc3-next-20080820 #13
>> [    0.146977]  [<c05c624f>] ? mutex_unlock+0xd/0xf
>> [    0.146977]  [<c0242944>] print_unlock_inbalance_bug+0xa5/0xb2
>> [    0.146977]  [<c05c624f>] ? mutex_unlock+0xd/0xf
>> [    0.146977]  [<c0245cd7>] lock_release+0x8f/0x186
>> [    0.146977]  [<c05c61f0>] __mutex_unlock_slowpath+0x9b/0xed
>> [    0.146977]  [<c05c624f>] mutex_unlock+0xd/0xf
>> [    0.146977]  [<c029506f>] free_bprm+0x24/0x39
>> [    0.146977]  [<c029644e>] do_execve+0x1e5/0x1fb
>> [    0.146977]  [<c0202156>] sys_execve+0x2e/0x51
>> [    0.146977]  [<c0203a72>] syscall_call+0x7/0xb
>> [    0.146977]  [<c0206654>] ? kernel_execve+0x1c/0x21
>> [    0.146977]  [<c023383c>] ? ____call_usermodehelper+0x0/0x129
>> [    0.146977]  [<c023395b>] ? ____call_usermodehelper+0x11f/0x129
>> [    0.146977]  [<c023383c>] ? ____call_usermodehelper+0x0/0x129
>> [    0.146977]  [<c020466b>] ? kernel_thread_helper+0x7/0x10
>> [    0.146977]  =======================
> 
> (config clipped)
> 
> Hi,
> 
> Thanks for the report. The error comes from
> 
> commit d9a939fb80ef390b78b3c801f668bd1e35ebc970
> Author: David Howells <dhowells@redhat.com>
> Date:   Thu Aug 7 20:02:20 2008 +1000
> 
>     CRED: Make execve() take advantage of copy-on-write credentials
> 
> (Added to Cc. I guess it's also nice to Cc linux-next on errors in -next code.)
> 
> I couldn't reproduce your original failure, but I've attempted to fix
> it by reordering the mutex unlock and bprm free and removing the
> extraneous unlock (see attached patch; it boots for me without
> errors).
> 
> 
> Vegard
> 
Hi,

Thanks, the patch fixes the "bad unlock balance" warning I was hitting
with the next-20080821 patchset.

Tested-by: Kamalesh Babulal <kamalesh@linux.vnet.ibm.com>

-- 
Thanks & Regards,
Kamalesh Babulal,
Linux Technology Center,
IBM, ISTL.

Re: Bug: "bad unlock balance detected" 2.6.27-rc3-next-20080820

[David Howells]

[-- Attachment #1: Type: text/plain, Size: 674 bytes --]

Vegard Nossum <vegard.nossum@gmail.com> wrote:

> I couldn't reproduce your original failure, but I've attempted to fix
> it by reordering the mutex unlock and bprm free and removing the
> extraneous unlock (see attached patch; it boots for me without
> errors).

Your patch ought to throw up its own lock failure.  You've added a
mutex_unlock() call to the execve success path, but you haven't removed one
from install_exec_creds().  Also, this patch is not sufficient as it doesn't
do anything for compat_do_execve().

Can you try the attached patches instead please?  You may find you have one or
more of them present already if you've pulled your tree recently.

David


[-- Warning: decoded text below may be mangled, UTF-8 assumed --]
[-- Attachment #2: 81-cred-compat-exec-mutex.diff --]
[-- Type: text/x-patch, Size: 2139 bytes --]

From: David Howells <dhowells@redhat.com>

CRED: Take cred_exec_mutex in compat_do_execve() and fix error handling in do_execve()

Take cred_exec_mutex in compat_do_execve().  This reflects what do_execve()
does.  The mutex protects credentials calculation against PTRACE_ATTACH needing
to alter it mid-exec.

Also fix the error handling in do_execve().  The mutex needs to be unlocked if
an error occurs after it is taken, but before the install_exec_creds()
released it.

Signed-off-by: David Howells <dhowells@redhat.com>
---

 fs/compat.c |   12 ++++++++++--
 fs/exec.c   |   12 ++++++++----
 2 files changed, 18 insertions(+), 6 deletions(-)


diff --git a/fs/compat.c b/fs/compat.c
index 2dde882..af24b8a 100644
--- a/fs/compat.c
+++ b/fs/compat.c
@@ -1360,15 +1360,20 @@ int compat_do_execve(char * filename,
 	if (!bprm)
 		goto out_ret;
 
+	retval = mutex_lock_interruptible(&current->cred_exec_mutex);
+	if (retval < 0)
+		goto out_free;
+
+	retval = -ENOMEM;
 	bprm->cred = prepare_exec_creds();
 	if (!bprm->cred)
-		goto out_free;
+		goto out_unlock;
 	check_unsafe_exec(bprm);
 
 	file = open_exec(filename);
 	retval = PTR_ERR(file);
 	if (IS_ERR(file))
-		goto out_free;
+		goto out_unlock;
 
 	sched_exec();
 
@@ -1423,6 +1428,9 @@ out_file:
 		fput(bprm->file);
 	}
 
+out_unlock:
+	mutex_unlock(&current->cred_exec_mutex);
+
 out_free:
 	free_bprm(bprm);
 
diff --git a/fs/exec.c b/fs/exec.c
index a7633e5..4b31a72 100644
--- a/fs/exec.c
+++ b/fs/exec.c
@@ -1308,18 +1308,18 @@ int do_execve(char * filename,
 
 	retval = mutex_lock_interruptible(&current->cred_exec_mutex);
 	if (retval < 0)
-		goto out_kfree;
+		goto out_free;
 
 	retval = -ENOMEM;
 	bprm->cred = prepare_exec_creds();
 	if (!bprm->cred)
-		goto out_kfree;
+		goto out_unlock;
 	check_unsafe_exec(bprm);
 
 	file = open_exec(filename);
 	retval = PTR_ERR(file);
 	if (IS_ERR(file))
-		goto out_kfree;
+		goto out_unlock;
 
 	sched_exec();
 
@@ -1376,7 +1376,11 @@ out_file:
 		allow_write_access(bprm->file);
 		fput(bprm->file);
 	}
-out_kfree:
+
+out_unlock:
+	mutex_unlock(&current->cred_exec_mutex);
+
+out_free:
 	free_bprm(bprm);
 
 out_files:

[-- Warning: decoded text below may be mangled, UTF-8 assumed --]
[-- Attachment #3: 82-cred-exec-mutex-error.diff --]
[-- Type: text/x-patch, Size: 1290 bytes --]

From: David Howells <dhowells@redhat.com>

CRED: Further fix execve error handling

Further fix [compat_]do_execve() error handling.  free_bprm() will release the
cred_exec_mutex, but only if bprm->cred is not NULL.

Signed-off-by: David Howells <dhowells@redhat.com>
---

 fs/compat.c |    3 ++-
 fs/exec.c   |    3 ++-
 2 files changed, 4 insertions(+), 2 deletions(-)


diff --git a/fs/compat.c b/fs/compat.c
index af24b8a..918f0f2 100644
--- a/fs/compat.c
+++ b/fs/compat.c
@@ -1373,7 +1373,7 @@ int compat_do_execve(char * filename,
 	file = open_exec(filename);
 	retval = PTR_ERR(file);
 	if (IS_ERR(file))
-		goto out_unlock;
+		goto out_free;
 
 	sched_exec();
 
@@ -1427,6 +1427,7 @@ out_file:
 		allow_write_access(bprm->file);
 		fput(bprm->file);
 	}
+	goto out_free;
 
 out_unlock:
 	mutex_unlock(&current->cred_exec_mutex);
diff --git a/fs/exec.c b/fs/exec.c
index 4b31a72..7b71679 100644
--- a/fs/exec.c
+++ b/fs/exec.c
@@ -1319,7 +1319,7 @@ int do_execve(char * filename,
 	file = open_exec(filename);
 	retval = PTR_ERR(file);
 	if (IS_ERR(file))
-		goto out_unlock;
+		goto out_free;
 
 	sched_exec();
 
@@ -1376,6 +1376,7 @@ out_file:
 		allow_write_access(bprm->file);
 		fput(bprm->file);
 	}
+	goto out_free;
 
 out_unlock:
 	mutex_unlock(&current->cred_exec_mutex);

[-- Warning: decoded text below may be mangled, UTF-8 assumed --]
[-- Attachment #4: 83-cred-move-exec-mutex.diff --]
[-- Type: text/x-patch, Size: 1622 bytes --]

From: David Howells <dhowells@redhat.com>

CRED: Move the exec mutex release out of bprm_free()

Move the exec mutex release out of free_bprm() and into the error handling
paths of do_execve() and compat_do_execve().  install_exec_creds() already
takes care of the success path.

Signed-off-by: David Howells <dhowells@redhat.com>
---

 fs/compat.c |    3 +--
 fs/exec.c   |    7 ++-----
 2 files changed, 3 insertions(+), 7 deletions(-)


diff --git a/fs/compat.c b/fs/compat.c
index 918f0f2..af24b8a 100644
--- a/fs/compat.c
+++ b/fs/compat.c
@@ -1373,7 +1373,7 @@ int compat_do_execve(char * filename,
 	file = open_exec(filename);
 	retval = PTR_ERR(file);
 	if (IS_ERR(file))
-		goto out_free;
+		goto out_unlock;
 
 	sched_exec();
 
@@ -1427,7 +1427,6 @@ out_file:
 		allow_write_access(bprm->file);
 		fput(bprm->file);
 	}
-	goto out_free;
 
 out_unlock:
 	mutex_unlock(&current->cred_exec_mutex);
diff --git a/fs/exec.c b/fs/exec.c
index 7b71679..9fa9a2d 100644
--- a/fs/exec.c
+++ b/fs/exec.c
@@ -1277,10 +1277,8 @@ EXPORT_SYMBOL(search_binary_handler);
 void free_bprm(struct linux_binprm *bprm)
 {
 	free_arg_pages(bprm);
-	if (bprm->cred) {
-		mutex_unlock(&current->cred_exec_mutex);
+	if (bprm->cred)
 		abort_creds(bprm->cred);
-	}
 	kfree(bprm);
 }
 
@@ -1319,7 +1317,7 @@ int do_execve(char * filename,
 	file = open_exec(filename);
 	retval = PTR_ERR(file);
 	if (IS_ERR(file))
-		goto out_free;
+		goto out_unlock;
 
 	sched_exec();
 
@@ -1376,7 +1374,6 @@ out_file:
 		allow_write_access(bprm->file);
 		fput(bprm->file);
 	}
-	goto out_free;
 
 out_unlock:
 	mutex_unlock(&current->cred_exec_mutex);

Re: Bug: "bad unlock balance detected" 2.6.27-rc3-next-20080820

[Vegard Nossum]

On Fri, Aug 22, 2008 at 3:04 PM, David Howells <dhowells@redhat.com> wrote:
>> I couldn't reproduce your original failure, but I've attempted to fix
>> it by reordering the mutex unlock and bprm free and removing the
>> extraneous unlock (see attached patch; it boots for me without
>> errors).
>
> Your patch ought to throw up its own lock failure.  You've added a
> mutex_unlock() call to the execve success path, but you haven't removed one
> from install_exec_creds().  Also, this patch is not sufficient as it doesn't
> do anything for compat_do_execve().

Ah, right. Thanks for the review anyway :-)

I didn't realize the lock should be held across the function call, I
will do a bit more research next time :-)

It seems to be a bit tricky. It would probably be nice to have
somebody else look at it too and verify that it is now indeed correct?


Vegard

-- 
"The animistic metaphor of the bug that maliciously sneaked in while
the programmer was not looking is intellectually dishonest as it
disguises that the error is the programmer's own creation."
	-- E. W. Dijkstra, EWD1036