Hi,

I got the following log from a rarely used PC that I just updated from
2.6.34-rc4 to 2.6.34-rc5.  I don't know though under which kernel I last
used the soundcard of it; could have been 2.6.33, could have been a
.34-rc.  It is an x86 Mac mini with

    00:1b.0 Audio device: Intel Corporation 82801G (ICH7 Family) High Definition Audio Controller (rev 02)

Kernel is vanilla except for various firewire patches, which should not
matter to this issue.

=================================
[ INFO: inconsistent lock state ]
2.6.34-rc5 #5
---------------------------------
inconsistent {HARDIRQ-ON-W} -> {IN-HARDIRQ-W} usage.
dolphin/4003 [HC1[1]:SC0[0]:HE0:SE1] takes:
(&(&tu->qlock)->rlock){?.+...}, at: [<f84ec472>] snd_timer_user_tinterrupt+0x28/0x132 [snd_timer]
{HARDIRQ-ON-W} state was registered at:
  [<c1048de9>] __lock_acquire+0x654/0x1482
  [<c1049c73>] lock_acquire+0x5c/0x73
  [<c125ac3e>] _raw_spin_lock+0x25/0x34
  [<f84ec370>] snd_timer_user_ccallback+0x55/0x95 [snd_timer]
  [<f84ecc4b>] snd_timer_notify1+0x53/0xca [snd_timer]
  [<f84ecdbe>] _snd_timer_stop+0xfc/0x106 [snd_timer]
  [<f84eceab>] snd_timer_stop+0x13/0x42 [snd_timer]
  [<f84ee2dc>] snd_timer_user_ioctl+0xa27/0xaf5 [snd_timer]
  [<c1092c2f>] vfs_ioctl+0x22/0x87
  [<c10931aa>] do_vfs_ioctl+0x472/0x4ac
  [<c1093210>] sys_ioctl+0x2c/0x45
  [<c1002850>] sysenter_do_call+0x12/0x36
irq event stamp: 2042234
hardirqs last  enabled at (2042233): [<c1002883>] sysenter_exit+0xf/0x18
hardirqs last disabled at (2042234): [<c1002d67>] common_interrupt+0x27/0x34
softirqs last  enabled at (2042226): [<c102cfc3>] __do_softirq+0x102/0x10a
softirqs last disabled at (2042221): [<c102cff6>] do_softirq+0x2b/0x43

other info that might help us debug this:
2 locks held by dolphin/4003:
 #0:  (snd_pcm_link_rwlock){.-....}, at: [<f8eb0a35>] snd_pcm_period_elapsed+0x2a/0xaf [snd_pcm]
 #1:  (&(&substream->self_group.lock)->rlock){-.....}, at: [<f8eb0a3f>] snd_pcm_period_elapsed+0x34/0xaf [snd_pcm]

stack backtrace:
Pid: 4003, ...
[ message continues ]

We should disable irqs when we take the tu->qlock because it is used in
the irq handler.  The only place that doesn't is
snd_timer_user_ccallback().  Most of the time snd_timer_user_ccallback()
is called with interrupts disabled but the the first ti->ccallback()
call in snd_timer_notify1() has interrupts enabled.


Reported-by: Stefan Richter <stefanr@s5r6.in-berlin.de>
Signed-off-by: Dan Carpenter <error27@gmail.com>

diff --git a/sound/core/timer.c b/sound/core/timer.c
index 7394365..5040c7b 100644
--- a/sound/core/timer.c
+++ b/sound/core/timer.c
@@ -1160,6 +1160,7 @@ static void snd_timer_user_ccallback(struct snd_timer_instance *timeri,
 {
 	struct snd_timer_user *tu = timeri->callback_data;
 	struct snd_timer_tread r1;
+	unsigned long flags;
 
 	if (event >= SNDRV_TIMER_EVENT_START &&
 	    event <= SNDRV_TIMER_EVENT_PAUSE)
@@ -1169,9 +1170,9 @@ static void snd_timer_user_ccallback(struct snd_timer_instance *timeri,
 	r1.event = event;
 	r1.tstamp = *tstamp;
 	r1.val = resolution;
-	spin_lock(&tu->qlock);
+	spin_lock_irqsave(&tu->qlock, flags);
 	snd_timer_user_append_to_tqueue(tu, &r1);
-	spin_unlock(&tu->qlock);
+	spin_unlock_irqrestore(&tu->qlock, flags);
 	kill_fasync(&tu->fasync, SIGIO, POLL_IN);
 	wake_up(&tu->qchange_sleep);
 }

--

[ message continues ]

At Wed, 28 Apr 2010 10:29:14 +0200,

Thanks, applied now.  Will be included in the next pull request.


--

[ message continues ]