2.6.19-rc3-git7: BUG: mutex warning sysfs_dir_open

2.6.19-rc3-git7: BUG: mutex warning sysfs_dir_open

[Mark Lord]

I don't know if the kernel is getting better at detecting its own bugs,
or if 2.6.19 is shaping up to be the flakiest kernel in recent memory.

I found this in my syslog just now:


kernel: BUG: warning at kernel/mutex.c:132/__mutex_lock_common()
kernel:  [<c0104088>] dump_trace+0x1c8/0x200
kernel:  [<c01040da>] show_trace_log_lvl+0x1a/0x30
kernel:  [<c0104832>] show_trace+0x12/0x20
kernel:  [<c0104999>] dump_stack+0x19/0x20
kernel:  [<c035d8ef>] __mutex_lock_slowpath+0x20f/0x260
kernel:  [<c035d961>] mutex_lock+0x21/0x30
kernel:  [<c01a0286>] sysfs_dir_open+0x26/0x60
kernel:  [<c0164925>] __dentry_open+0xb5/0x1e0
kernel:  [<c0164af5>] nameidata_to_filp+0x35/0x40
kernel:  [<c0164b49>] do_filp_open+0x49/0x50
kernel:  [<c0164b97>] do_sys_open+0x47/0xe0
kernel:  [<c0164c6c>] sys_open+0x1c/0x20
kernel:  [<c0102f4d>] sysenter_past_esp+0x56/0x8d
kernel:  [<b7fc5410>] 0xb7fc5410
kernel:  =======================
kernel: BUG: unable to handle kernel paging request at virtual address 6e726574
kernel:  printing eip:
kernel: c022a8fc
kernel: *pde = 00000000
kernel: Oops: 0000 [#1]
kernel: SMP
kernel: Modules linked in: button battery ac dm_mod snd_hda_intel snd_hda_codec snd_pcm snd_timer snd soundcore snd_page_alloc r1000 ahci edd fan thermal processor
kernel: CPU:    0
kernel: EIP:    0060:[<c022a8fc>]    Not tainted VLI
kernel: EFLAGS: 00010046   (2.6.19-rc3-git7-ml #9)
kernel: EIP is at __list_add+0x1c/0x80
kernel: eax: 6e726574   ebx: dfe39120   ecx: dfe39120   edx: 6e726574
kernel: esi: 6e726574   edi: f7861ea4   ebp: f7861e88   esp: f7861e70
kernel: ds: 007b   es: 007b   ss: 0068
kernel: Process hald (pid: 3360, ti=f7860000 task=f7974af0 task.ti=f7860000)
kernel: Stack: 00000000 00000002 00000001 dfe39100 00000246 f7974af0 f7861ec4 c035d76e
kernel:        00000000 00000002 c035d961 c0362479 dfe39120 f7861ea4 f7861ea4 11111111
kernel:        dfe39100 f7861ea4 dfe39100 f753ac00 dfe3a8a4 f7861ed0 c035d961 f78c0b34
kernel: Call Trace:
kernel:  [<c035d76e>] __mutex_lock_slowpath+0x8e/0x260
kernel:  [<c035d961>] mutex_lock+0x21/0x30
kernel:  [<c01a0286>] sysfs_dir_open+0x26/0x60
kernel:  [<c0164925>] __dentry_open+0xb5/0x1e0
kernel:  [<c0164af5>] nameidata_to_filp+0x35/0x40
kernel:  [<c0164b49>] do_filp_open+0x49/0x50
kernel:  [<c0164b97>] do_sys_open+0x47/0xe0
kernel:  [<c0164c6c>] sys_open+0x1c/0x20
kernel:  [<c0102f4d>] sysenter_past_esp+0x56/0x8d
kernel:  [<b7fc5410>] 0xb7fc5410
kernel:  =======================
kernel: Code: 13 eb a7 8d b6 00 00 00 00 8d bf 00 00 00 00 55 89 e5 83 ec 18 89 5d f4 89 cb 89 75 f8 89 d6 89 7d fc 89 c7 8b 41 04 39 d0 75 1d <8b> 06 39 c3 75 35 89 7b 04 89 1f 8b 5d f4 89 77 04 89 3e 8b 75
kernel: EIP: [<c022a8fc>] __list_add+0x1c/0x80 SS:ESP 0068:f7861e70
kernel:  <3>BUG: sleeping function called from invalid context at kernel/rwsem.c:20
kernel: in_atomic():0, irqs_disabled():1
kernel:  [<c0104088>] dump_trace+0x1c8/0x200
kernel:  [<c01040da>] show_trace_log_lvl+0x1a/0x30
kernel:  [<c0104832>] show_trace+0x12/0x20
kernel:  [<c0104999>] dump_stack+0x19/0x20
kernel:  [<c01166f8>] __might_sleep+0xa8/0xb0
kernel:  [<c0134468>] down_read+0x18/0x60
kernel:  [<c0143869>] acct_collect+0x39/0x150
kernel:  [<c0120715>] do_exit+0xf5/0x8a0
kernel:  [<c0104725>] die+0x2f5/0x300
kernel:  [<c0114c0f>] do_page_fault+0x1ff/0x5f0
kernel:  [<c035f0a9>] error_code+0x39/0x40
kernel:  [<c022a8fc>] __list_add+0x1c/0x80
kernel:  [<c035d76e>] __mutex_lock_slowpath+0x8e/0x260
kernel:  [<c035d961>] mutex_lock+0x21/0x30
kernel:  [<c01a0286>] sysfs_dir_open+0x26/0x60
kernel:  [<c0164925>] __dentry_open+0xb5/0x1e0
kernel:  [<c0164af5>] nameidata_to_filp+0x35/0x40
kernel:  [<c0164b49>] do_filp_open+0x49/0x50
kernel:  [<c0164b97>] do_sys_open+0x47/0xe0
kernel:  [<c0164c6c>] sys_open+0x1c/0x20
kernel:  [<c0102f4d>] sysenter_past_esp+0x56/0x8d
kernel:  [<b7fc5410>] 0xb7fc5410
kernel:  =======================
silvy:~#                                     

Re: 2.6.19-rc3-git7: BUG: mutex warning sysfs_dir_open

[Linus Torvalds]

On Tue, 31 Oct 2006, Mark Lord wrote:
> 
> I found this in my syslog just now:
> 
> kernel: BUG: warning at kernel/mutex.c:132/__mutex_lock_common()

That's the "spin_lock_mutex()" debugging (kernel/mutex-debug.h), and it's 
one of either

	DEBUG_LOCKS_WARN_ON(in_interrupt());
or
	DEBUG_LOCKS_WARN_ON(l->magic != l);

where the much more likely one is the "l->magic" one triggering, because 
your bug that follows is:

> kernel: BUG: unable to handle kernel paging request at virtual address 6e726574

64726574 is "tern", for whatever that's worth, and that EIP is in 
"__list_add()", which comes from list_add_tail(), and so it looks like the 
mutex "lock->lock_list" is also totally buggered (which would certainly 
fit with the lock "magic" field being crud too).

> kernel: Call Trace:
> kernel:  [<c035d76e>] __mutex_lock_slowpath+0x8e/0x260
> kernel:  [<c035d961>] mutex_lock+0x21/0x30
> kernel:  [<c01a0286>] sysfs_dir_open+0x26/0x60

This would be

	mutex_lock(&dentry->d_inode->i_mutex);

in sysfs_dir_open(), so you would seem to have an inode that is 
overwritten by crud (or it could be a dentry with a bogus d_inode 
pointer, of course).

There's a ton of stuff with "tern" in it, mostly "Internal", so sadly even 
the nice string pattern doesn't seem to be all that helpful.

Is this somewhat reproducible? 

HOWEVER, google does find a clue. We've had reports of something somewhat 
similar before: googling for "__mutex_lock_slowpath" and "sysfs_dir_open" 
shows for example

	http://lkml.org/lkml/2006/8/18/72

where the thread ended up first blaming sound, but then deciding that 
maybe it was DRM-related. However, you don't seem to have any AGP or DRM 
support at all, so maybe it really _is_ a sound problem.

Mark - can you verify that you don't have any DRM support in your kernel?

Frederic, Takashi, did that bug-report ever get resolved?

		Linus

Re: 2.6.19-rc3-git7: BUG: mutex warning sysfs_dir_open

[Mark Lord]

Linus Torvalds wrote:
> 
> Is this somewhat reproducible? 

Just the one occurance of it, with rc3-git7.
I've now moved on to -rc4.

> HOWEVER, google does find a clue. We've had reports of something somewhat 
> similar before: googling for "__mutex_lock_slowpath" and "sysfs_dir_open" 
> shows for example
> 
> 	http://lkml.org/lkml/2006/8/18/72
> 
> where the thread ended up first blaming sound, but then deciding that 
> maybe it was DRM-related. However, you don't seem to have any AGP or DRM 
> support at all, so maybe it really _is_ a sound problem.
> 
> Mark - can you verify that you don't have any DRM support in your kernel?

# CONFIG_DRM is not set

(but I'm about to change that!).

Cheers

Re: 2.6.19-rc3-git7: BUG: mutex warning sysfs_dir_open

[Takashi Iwai]

At Tue, 31 Oct 2006 09:53:35 -0800 (PST),
Linus Torvalds wrote:
> 
> 
> 
> On Tue, 31 Oct 2006, Mark Lord wrote:
> > 
> > I found this in my syslog just now:
> > 
> > kernel: BUG: warning at kernel/mutex.c:132/__mutex_lock_common()
> 
> That's the "spin_lock_mutex()" debugging (kernel/mutex-debug.h), and it's 
> one of either
> 
> 	DEBUG_LOCKS_WARN_ON(in_interrupt());
> or
> 	DEBUG_LOCKS_WARN_ON(l->magic != l);
> 
> where the much more likely one is the "l->magic" one triggering, because 
> your bug that follows is:
> 
> > kernel: BUG: unable to handle kernel paging request at virtual address 6e726574
> 
> 64726574 is "tern", for whatever that's worth, and that EIP is in 
> "__list_add()", which comes from list_add_tail(), and so it looks like the 
> mutex "lock->lock_list" is also totally buggered (which would certainly 
> fit with the lock "magic" field being crud too).
> 
> > kernel: Call Trace:
> > kernel:  [<c035d76e>] __mutex_lock_slowpath+0x8e/0x260
> > kernel:  [<c035d961>] mutex_lock+0x21/0x30
> > kernel:  [<c01a0286>] sysfs_dir_open+0x26/0x60
> 
> This would be
> 
> 	mutex_lock(&dentry->d_inode->i_mutex);
> 
> in sysfs_dir_open(), so you would seem to have an inode that is 
> overwritten by crud (or it could be a dentry with a bogus d_inode 
> pointer, of course).
> 
> There's a ton of stuff with "tern" in it, mostly "Internal", so sadly even 
> the nice string pattern doesn't seem to be all that helpful.
> 
> Is this somewhat reproducible? 
> 
> HOWEVER, google does find a clue. We've had reports of something somewhat 
> similar before: googling for "__mutex_lock_slowpath" and "sysfs_dir_open" 
> shows for example
> 
> 	http://lkml.org/lkml/2006/8/18/72
> 
> where the thread ended up first blaming sound, but then deciding that 
> maybe it was DRM-related. However, you don't seem to have any AGP or DRM 
> support at all, so maybe it really _is_ a sound problem.
> 
> Mark - can you verify that you don't have any DRM support in your kernel?
> 
> Frederic, Takashi, did that bug-report ever get resolved?

IIRC, in Frederik's case, it turned out to be irrelevant from the
sound stuff since the bug occured even before loading ALSA modules.

Of course, it still _might_ be a sound problem :)

It'd be nice if we can see what sysfs entry triggers bugs...


Takashi