Re: 2.6.21-rc6-mm1 ima "BUG: held lock freed!"

Re: 2.6.21-rc6-mm1 ima "BUG: held lock freed!"

[Reiner Sailer]

We are looking into this.
Thanks!
Reiner

--forwarded by Reiner Sailer:
On Sun, Apr 08, 2007 at 02:35:59PM -0700, Andrew Morton wrote:
 >
 > 
ftp://ftp.kernel.org/pub/linux/kernel/people/akpm/patches/2.6/2.6.21-rc6/2.6.21-rc6-mm1/
 >
    I'm seeing this while booting:

ima (ima_init): No TPM chip found(rc = -19), activating TPM-bypass!

=========================
[ BUG: held lock freed! ]
-------------------------
swapper/1 is freeing memory c04c7660-c04c76a3, with a lock still held there!
 (ima_queue_lock){--..}, at: [<c0202710>] ima_create_htable+0x10/0x90
1 lock held by swapper/1:
 #0:  (ima_queue_lock){--..}, at: [<c0202710>] ima_create_htable+0x10/0x90

stack backtrace:
 [<c0105959>] dump_trace+0x1d9/0x210
 [<c01059aa>] show_trace_log_lvl+0x1a/0x30
 [<c0106612>] show_trace+0x12/0x20
 [<c01066d6>] dump_stack+0x16/0x20
 [<c014fd3a>] debug_check_no_locks_freed+0x17a/0x180
 [<c014cdbf>] debug_mutex_init+0x1f/0x50
 [<c0145451>] __mutex_init+0x41/0x50
 [<c020277d>] ima_create_htable+0x7d/0x90
 [<c020286f>] ima_init+0x3f/0x270
 [<c051b765>] init_evm+0x1f5/0x250
 [<c05015d2>] kernel_init+0x132/0x320
 [<c010532f>] kernel_thread_helper+0x7/0x18
 =======================

    I saw this in -rc5-mm4 also.

    I couldn't find a contact address in MAINTAINERS, so I've CC'd the
two authors listed on top of ima_create_htable.c , as well as the
first submitter of the IMA stuff I found in my LKML archive.

    As an aside, this computer does have (some sort of) TPM chip, but
the driver is built as a module, and not loaded at this point (not a
worry for me, I don't intend to use it).

--
Joseph Fannin
jfannin@gmail.com || jhf@columbus.rr.com

Re: 2.6.21-rc6-mm1 ima "BUG: held lock freed!"

[Reiner Sailer]

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

Joseph,

we cannot reproduce the BUG you report. We have identified a potential 
source (spinlock around mutex_init). I have attached a small patch that 
removes this lock from the initialization of the hash table. I have 
tested the patch but I cannot verify if this resolves the problem you 
are seeing.

If you can reproduce the problem, would you mind to apply this patch and 
let us know if this solves the problem?

Thanks
Reiner

Reiner Sailer wrote:
>
> We are looking into this.
> Thanks!
> Reiner
>
> --forwarded by Reiner Sailer:
> On Sun, Apr 08, 2007 at 02:35:59PM -0700, Andrew Morton wrote:
> >
> > 
> ftp://ftp.kernel.org/pub/linux/kernel/people/akpm/patches/2.6/2.6.21-rc6/2.6.21-rc6-mm1/ 
>
> >
>    I'm seeing this while booting:
>
> ima (ima_init): No TPM chip found(rc = -19), activating TPM-bypass!
>
> =========================
> [ BUG: held lock freed! ]
> -------------------------
> swapper/1 is freeing memory c04c7660-c04c76a3, with a lock still held 
> there!
> (ima_queue_lock){--..}, at: [<c0202710>] ima_create_htable+0x10/0x90
> 1 lock held by swapper/1:
> #0:  (ima_queue_lock){--..}, at: [<c0202710>] ima_create_htable+0x10/0x90
>
> stack backtrace:
> [<c0105959>] dump_trace+0x1d9/0x210
> [<c01059aa>] show_trace_log_lvl+0x1a/0x30
> [<c0106612>] show_trace+0x12/0x20
> [<c01066d6>] dump_stack+0x16/0x20
> [<c014fd3a>] debug_check_no_locks_freed+0x17a/0x180
> [<c014cdbf>] debug_mutex_init+0x1f/0x50
> [<c0145451>] __mutex_init+0x41/0x50
> [<c020277d>] ima_create_htable+0x7d/0x90
> [<c020286f>] ima_init+0x3f/0x270
> [<c051b765>] init_evm+0x1f5/0x250
> [<c05015d2>] kernel_init+0x132/0x320
> [<c010532f>] kernel_thread_helper+0x7/0x18
> =======================
>
>    I saw this in -rc5-mm4 also.
>
>    I couldn't find a contact address in MAINTAINERS, so I've CC'd the
> two authors listed on top of ima_create_htable.c , as well as the
> first submitter of the IMA stuff I found in my LKML archive.
>
>    As an aside, this computer does have (some sort of) TPM chip, but
> the driver is built as a module, and not loaded at this point (not a
> worry for me, I don't intend to use it).
>
> -- 
> Joseph Fannin
> jfannin@gmail.com || jhf@columbus.rr.com
>



[-- Attachment #2: ima-init-lock-fix.patch --]
[-- Type: text/plain, Size: 702 bytes --]

---
 security/evm/ima/ima_queue.c |    2 --
 1 file changed, 2 deletions(-)

Index: linux-2.6.21-rc6/security/evm/ima/ima_queue.c
===================================================================
--- linux-2.6.21-rc6.orig/security/evm/ima/ima_queue.c
+++ linux-2.6.21-rc6/security/evm/ima/ima_queue.c
@@ -38,7 +38,6 @@ void ima_create_htable(void)
 {
 	int i;
 
-	spin_lock(&ima_queue_lock);
 	INIT_LIST_HEAD(&ima_measurements);
 	atomic_set(&ima_htable.len, 0);
 	atomic_set(&ima_htable.violations, 0);
@@ -50,7 +49,6 @@ void ima_create_htable(void)
 	}
 
 	mutex_init(&ima_extend_list_mutex);
-	spin_unlock(&ima_queue_lock);
 }
 
 struct ima_queue_entry *ima_lookup_digest_entry(u8 * digest_value)

Re: 2.6.21-rc6-mm1 ima "BUG: held lock freed!"

[Joseph Fannin]

On Tue, 2007-04-10 at 15:00 -0400, Reiner Sailer wrote:
> Joseph,
> 
> we cannot reproduce the BUG you report. We have identified a potential 
> source (spinlock around mutex_init). I have attached a small patch that 
> removes this lock from the initialization of the hash table. I have 
> tested the patch but I cannot verify if this resolves the problem you 
> are seeing.
> 
> If you can reproduce the problem, would you mind to apply this patch and 
> let us know if this solves the problem?

The BUG message no longer appears with this patch applied.  It was 100%
reproducible before, so I think this fixed it.

Thanks!

--
Joseph Fannin
jfannin@gmail.com || jhf@columbus.rr.com

> >    I'm seeing this while booting:
> >
> > ima (ima_init): No TPM chip found(rc = -19), activating TPM-bypass!
> >
> > =========================
> > [ BUG: held lock freed! ]
> > -------------------------
> > swapper/1 is freeing memory c04c7660-c04c76a3, with a lock still held 
> > there!
> > (ima_queue_lock){--..}, at: [<c0202710>] ima_create_htable+0x10/0x90
> > 1 lock held by swapper/1:
> > #0:  (ima_queue_lock){--..}, at: [<c0202710>] ima_create_htable+0x10/0x90
> >
> > stack backtrace:
> > [<c0105959>] dump_trace+0x1d9/0x210
> > [<c01059aa>] show_trace_log_lvl+0x1a/0x30
> > [<c0106612>] show_trace+0x12/0x20
> > [<c01066d6>] dump_stack+0x16/0x20
> > [<c014fd3a>] debug_check_no_locks_freed+0x17a/0x180
> > [<c014cdbf>] debug_mutex_init+0x1f/0x50
> > [<c0145451>] __mutex_init+0x41/0x50
> > [<c020277d>] ima_create_htable+0x7d/0x90
> > [<c020286f>] ima_init+0x3f/0x270
> > [<c051b765>] init_evm+0x1f5/0x250
> > [<c05015d2>] kernel_init+0x132/0x320
> > [<c010532f>] kernel_thread_helper+0x7/0x18
> > =======================
> >
> >    I saw this in -rc5-mm4 also.
> >
> >    I couldn't find a contact address in MAINTAINERS, so I've CC'd the
> > two authors listed on top of ima_create_htable.c , as well as the
> > first submitter of the IMA stuff I found in my LKML archive.
> >
> >    As an aside, this computer does have (some sort of) TPM chip, but
> > the driver is built as a module, and not loaded at this point (not a
> > worry for me, I don't intend to use it).
> >

Re: 2.6.21-rc6-mm1 ima "BUG: held lock freed!"

[Andrew Morton]

On Wed, 11 Apr 2007 09:55:18 -0400
Joseph Fannin <jhf@columbus.rr.com> wrote:

> On Tue, 2007-04-10 at 15:00 -0400, Reiner Sailer wrote:
> > Joseph,
> > 
> > we cannot reproduce the BUG you report. We have identified a potential 
> > source (spinlock around mutex_init). I have attached a small patch that 
> > removes this lock from the initialization of the hash table. I have 
> > tested the patch but I cannot verify if this resolves the problem you 
> > are seeing.
> > 
> > If you can reproduce the problem, would you mind to apply this patch and 
> > let us know if this solves the problem?
> 
> The BUG message no longer appears with this patch applied.  It was 100%
> reproducible before, so I think this fixed it.

ok, the spinlock in there was unneeded anwyay.

But I think this is a lockdep shortcoming - there's nothing wrong with
doing mutex_init() inside spin_lock().

debug_mutex_init() is trying to work out whether we're initialising
an already held mutex.  This has nothing to do with the spinlock
which we're holding.  Perhaps debug_check_no_locks_freed() simply
went wrong.

For Ingo - this:

=========================
[ BUG: held lock freed! ]
-------------------------
swapper/1 is freeing memory c04c7660-c04c76a3, with a lock still held there!
 (ima_queue_lock){--..}, at: [<c0202710>] ima_create_htable+0x10/0x90
1 lock held by swapper/1:
 #0:  (ima_queue_lock){--..}, at: [<c0202710>] ima_create_htable+0x10/0x90

stack backtrace:
 [<c0105959>] dump_trace+0x1d9/0x210
 [<c01059aa>] show_trace_log_lvl+0x1a/0x30
 [<c0106612>] show_trace+0x12/0x20
 [<c01066d6>] dump_stack+0x16/0x20
 [<c014fd3a>] debug_check_no_locks_freed+0x17a/0x180
 [<c014cdbf>] debug_mutex_init+0x1f/0x50
 [<c0145451>] __mutex_init+0x41/0x50
 [<c020277d>] ima_create_htable+0x7d/0x90
 [<c020286f>] ima_init+0x3f/0x270
 [<c051b765>] init_evm+0x1f5/0x250
 [<c05015d2>] kernel_init+0x132/0x320
 [<c010532f>] kernel_thread_helper+0x7/0x18
 =======================

is coming out of -mm's security/evm/ima/ima_queue.c:ima_create_htable().

Re: 2.6.21-rc6-mm1 ima "BUG: held lock freed!"

[Joseph Fannin]

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

On Sun, Apr 08, 2007 at 02:35:59PM -0700, Andrew Morton wrote:
>
> ftp://ftp.kernel.org/pub/linux/kernel/people/akpm/patches/2.6/2.6.21-rc6/2.6.21-rc6-mm1/
>
    I'm seeing this while booting:

ima (ima_init): No TPM chip found(rc = -19), activating TPM-bypass!

=========================
[ BUG: held lock freed! ]
-------------------------
swapper/1 is freeing memory c04c7660-c04c76a3, with a lock still held there!
 (ima_queue_lock){--..}, at: [<c0202710>] ima_create_htable+0x10/0x90
1 lock held by swapper/1:
 #0:  (ima_queue_lock){--..}, at: [<c0202710>] ima_create_htable+0x10/0x90

stack backtrace:
 [<c0105959>] dump_trace+0x1d9/0x210
 [<c01059aa>] show_trace_log_lvl+0x1a/0x30
 [<c0106612>] show_trace+0x12/0x20
 [<c01066d6>] dump_stack+0x16/0x20
 [<c014fd3a>] debug_check_no_locks_freed+0x17a/0x180
 [<c014cdbf>] debug_mutex_init+0x1f/0x50
 [<c0145451>] __mutex_init+0x41/0x50
 [<c020277d>] ima_create_htable+0x7d/0x90
 [<c020286f>] ima_init+0x3f/0x270
 [<c051b765>] init_evm+0x1f5/0x250
 [<c05015d2>] kernel_init+0x132/0x320
 [<c010532f>] kernel_thread_helper+0x7/0x18
 =======================

    I saw this in -rc5-mm4 also.

    I couldn't find a contact address in MAINTAINERS, so I've CC'd the
two authors listed on top of ima_create_htable.c , as well as the
first submitter of the IMA stuff I found in my LKML archive.

    As an aside, this computer does have (some sort of) TPM chip, but
the driver is built as a module, and not loaded at this point (not a
worry for me, I don't intend to use it).

--
Joseph Fannin
jfannin@gmail.com || jhf@columbus.rr.com

[-- Attachment #2: Digital signature --]
[-- Type: application/pgp-signature, Size: 189 bytes --]