tasklet_unlock_wait() causes soft lockup with -rt and ieee1394 audio

tasklet_unlock_wait() causes soft lockup with -rt and ieee1394 audio

[Lee Revell]

Pieter has found this bug in -rt:

We are experiencing 'soft' deadlocks when running our code (Freebob, 
i.e. userspace lib for firewire audio) on RT kernels. After a few 
seconds of system freeze, I get a kernel panic message that signals a soft lockup.

I've uploaded the photo's of the panic here:
http://freebob.sourceforge.net/old/img_3378.jpg (without flash)
http://freebob.sourceforge.net/old/img_3377.jpg (with flash)
both are of suboptimal quality unfortunately, but all info is readable 
on one or the other.

The problems occur when an ISO stream (receive and/or transmit) is shut 
down in a SCHED_FIFO thread. More precisely when running the freebob 
jackd backend in real-time mode. And even more precise: they only seem 
to occur when jackd is shut down. There are no problems when jackd is 
started without RT scheduling.

I havent been able to reproduce this with other test programs that are 
shutting down streams in a SCHED_FIFO thread.

The problem is not reproducible on non-RT kernels, and it only occurs on those configured for 
PREEMPT_RT. If I use PREEMPT_DESKTOP, there is no problem. The PREEMPT_DESKTOP setting was the only change between the two tests, all other kernel settings (threaded irq's etc...) were unchanged.

My tests are performed on 2.6.17-rt1, but the lockups are confirmed for 
PREEMPT_RT configured kernels 2.6.14 and 2.6.16.

Some extra information:

Lee Revell wrote:

> <...>
>
> It seems that the -rt patch changes tasklet_kill:
>
> Unpatched 2.6.17:
>
> void tasklet_kill(struct tasklet_struct *t)
> {
>         if (in_interrupt())
>                 printk("Attempt to kill tasklet from interrupt\n");
>
>         while (test_and_set_bit(TASKLET_STATE_SCHED, &t->state)) {
>                 do
>                         yield();
>                 while (test_bit(TASKLET_STATE_SCHED, &t->state));
>         }
>         tasklet_unlock_wait(t);
>         clear_bit(TASKLET_STATE_SCHED, &t->state);
> }
>
> 2.6.17-rt:
>
> void tasklet_kill(struct tasklet_struct *t)
> {
>         if (in_interrupt())
>                 printk("Attempt to kill tasklet from interrupt\n");
>
>         while (test_and_set_bit(TASKLET_STATE_SCHED, &t->state)) {
>                 do                              msleep(1);
>                 while (test_bit(TASKLET_STATE_SCHED, &t->state));
>         }
>         tasklet_unlock_wait(t);
>         clear_bit(TASKLET_STATE_SCHED, &t->state);
> }
>
> You should ask Ingo & the other -rt developers what the intent of this
> change was.  Obviously it loops forever waiting for the state bit to
> change.

On Thu, 2006-07-06 at 22:14 +0200, Pieter Palmers wrote:

> > I've put the debugging printk's into tasklet_kill. One interesting 
> > remark is that now that they are in place, I had to start/stop jackd 
> > multiple times before deadlock occurs. Without the printk's the machine 
> > always locked up on the first pass. However I stopped after the first 
> > lockup, so maybe this is not really significant.
> > 
> > Anyway, the new tasklet_kill looks like this:
> > 
> > void tasklet_kill(struct tasklet_struct *t)
> > {
> > 	printk("enter tasklet_kill\n");
> > 	if (in_interrupt())
> > 		printk("Attempt to kill tasklet from interrupt\n");
> > 	
> > 	printk("passed interrupt check\n");
> > 
> > 	while (test_and_set_bit(TASKLET_STATE_SCHED, &t->state)) {
> > 		do
> > 			msleep(1);
> > 		while (test_bit(TASKLET_STATE_SCHED, &t->state));
> > 	}
> > 	printk("passed test_and_set_bit\n");
> > 	
> > 	tasklet_unlock_wait(t);
> > 	printk("passed tasklet_unlock_wait\n");
> > 	
> > 	clear_bit(TASKLET_STATE_SCHED, &t->state);
> > }
> > 
> > And the last line printed before lockup is:
> > "passed test_and_set_bit"
>   
This makes the change in tasklet_unlock_wait() as the prime suspect for this problem.

Re: tasklet_unlock_wait() causes soft lockup with -rt and ieee1394 audio

[Steven Rostedt]

Hi Lee,

Sorry, I've been quiet, and will be again soon.  I'm in a process of
changing jobs, and I am now employed by Red Hat and will soon be working
on Xen.

Anyway, I'll take a look at what you got and see if I can help at all.

On Sat, 2006-07-08 at 11:18 -0400, Lee Revell wrote:
> Pieter has found this bug in -rt:
> 
> We are experiencing 'soft' deadlocks when running our code (Freebob, 
> i.e. userspace lib for firewire audio) on RT kernels. After a few 
> seconds of system freeze, I get a kernel panic message that signals a soft lockup.
> 
> I've uploaded the photo's of the panic here:
> http://freebob.sourceforge.net/old/img_3378.jpg (without flash)

uw, what a headache.

> http://freebob.sourceforge.net/old/img_3377.jpg (with flash)

Hmm no headache but hard to read. Good that the functions
ohci1394_unregister_iso_tasklet and down are readable, and those are the
important information.

> both are of suboptimal quality unfortunately, but all info is readable 
> on one or the other.

yep.

> 
> The problems occur when an ISO stream (receive and/or transmit) is shut 
> down in a SCHED_FIFO thread. More precisely when running the freebob 
> jackd backend in real-time mode. And even more precise: they only seem 
> to occur when jackd is shut down. There are no problems when jackd is 
> started without RT scheduling.
> 
> I havent been able to reproduce this with other test programs that are 
> shutting down streams in a SCHED_FIFO thread.
> 
> The problem is not reproducible on non-RT kernels, and it only occurs on those configured for 
> PREEMPT_RT. If I use PREEMPT_DESKTOP, there is no problem. The PREEMPT_DESKTOP setting was the only change between the two tests, all other kernel settings (threaded irq's etc...) were unchanged.
> 
> My tests are performed on 2.6.17-rt1, but the lockups are confirmed for 
> PREEMPT_RT configured kernels 2.6.14 and 2.6.16.
> 
> Some extra information:
> 
> Lee Revell wrote:
> 
> > <...>
> >
> > It seems that the -rt patch changes tasklet_kill:
> >
> > Unpatched 2.6.17:
> >
> > void tasklet_kill(struct tasklet_struct *t)
> > {
> >         if (in_interrupt())
> >                 printk("Attempt to kill tasklet from interrupt\n");
> >
> >         while (test_and_set_bit(TASKLET_STATE_SCHED, &t->state)) {
> >                 do
> >                         yield();

Very bad for -rt kernels.

> >                 while (test_bit(TASKLET_STATE_SCHED, &t->state));
> >         }
> >         tasklet_unlock_wait(t);
> >         clear_bit(TASKLET_STATE_SCHED, &t->state);
> > }
> >
> > 2.6.17-rt:
> >
> > void tasklet_kill(struct tasklet_struct *t)
> > {
> >         if (in_interrupt())
> >                 printk("Attempt to kill tasklet from interrupt\n");
> >
> >         while (test_and_set_bit(TASKLET_STATE_SCHED, &t->state)) {
> >                 do                              msleep(1);
> >                 while (test_bit(TASKLET_STATE_SCHED, &t->state));
> >         }
> >         tasklet_unlock_wait(t);
> >         clear_bit(TASKLET_STATE_SCHED, &t->state);
> > }
> >
> > You should ask Ingo & the other -rt developers what the intent of this
> > change was.  Obviously it loops forever waiting for the state bit to
> > change.

The reason for this is that yield is just evil.  And even more evil for
-rt.  What yield does is this:  Process is waiting for something to
happen that will be done by another running process, and instead of
using a wait queue or some other method, it simply spins with the yield,
to let the other task do it.  But with a rt task, yield will only yield
to other processes with the same priority or higher, so if the process
that it is waiting on is of lower priority, then you will spin forever.

The msleep replacement is just a hack and not really a solution.  It
puts the task to sleep, for one ms, to let other tasks run.  Now, if
there's another task of higher priority spinning someplace else, then
you can still starve the task you are waiting on.

We are probably in tasklet_unlock_wait which is:

static inline void tasklet_unlock_wait(struct tasklet_struct *t)
{
	while (test_bit(TASKLET_STATE_RUN, &(t)->state)) { barrier(); }
}

Which just looks scary.

Ingo, this looks really bad if the process killing the tasklet, preempts
the tasklet on wake up in the tasklet_kill msleep, and the tasklet state
happens to be TASKLET_STATE_RUN.  Perhaps, we need a msleep_rt which
only sleeps if PREEMPT_RT is defined, and put that in by the barrier.

Lee, can you cause this problem with PREEMPT_DESKTOP with softirq as
threads?

Also, add a msleep(1); by the barrier(); and see if that solves the
problem.

> 
> On Thu, 2006-07-06 at 22:14 +0200, Pieter Palmers wrote:
> 
> > > I've put the debugging printk's into tasklet_kill. One interesting 
> > > remark is that now that they are in place, I had to start/stop jackd 
> > > multiple times before deadlock occurs. Without the printk's the machine 
> > > always locked up on the first pass. However I stopped after the first 
> > > lockup, so maybe this is not really significant.
> > > 
> > > Anyway, the new tasklet_kill looks like this:
> > > 
> > > void tasklet_kill(struct tasklet_struct *t)
> > > {
> > > 	printk("enter tasklet_kill\n");
> > > 	if (in_interrupt())
> > > 		printk("Attempt to kill tasklet from interrupt\n");
> > > 	
> > > 	printk("passed interrupt check\n");
> > > 
> > > 	while (test_and_set_bit(TASKLET_STATE_SCHED, &t->state)) {
> > > 		do
> > > 			msleep(1);
> > > 		while (test_bit(TASKLET_STATE_SCHED, &t->state));
> > > 	}
> > > 	printk("passed test_and_set_bit\n");
> > > 	
> > > 	tasklet_unlock_wait(t);
> > > 	printk("passed tasklet_unlock_wait\n");
> > > 	
> > > 	clear_bit(TASKLET_STATE_SCHED, &t->state);
> > > }
> > > 
> > > And the last line printed before lockup is:
> > > "passed test_and_set_bit"
> >   
> This makes the change in tasklet_unlock_wait() as the prime suspect for this problem.

This looks like the case.

-- Steve

Re: tasklet_unlock_wait() causes soft lockup with -rt and ieee1394 audio

[Lee Revell]

On Sat, 2006-07-08 at 21:51 -0400, Steven Rostedt wrote:
> Lee, can you cause this problem with PREEMPT_DESKTOP with softirq as
> threads?
> 

I am just posting this for Pieter - all followups should be directed to
him.  (I don't even have the hardware to reproduce this)

IIRC the problem could only be reproduced with PREEMPT_RT.  Pieter, can
you confirm?

Lee

Re: tasklet_unlock_wait() causes soft lockup with -rt and ieee1394 audio

[Pieter Palmers]

Lee Revell wrote:
> On Sat, 2006-07-08 at 21:51 -0400, Steven Rostedt wrote:
>> Lee, can you cause this problem with PREEMPT_DESKTOP with softirq as
>> threads?
>>
> 
> I am just posting this for Pieter - all followups should be directed to
> him.  (I don't even have the hardware to reproduce this)
> 
> IIRC the problem could only be reproduced with PREEMPT_RT.  Pieter, can
> you confirm?

It can only be reproduced with PREEMPT_RT. And the test kernel is 
configured with irq threading, I haven't tried it without irq threading.

Pieter

Re: tasklet_unlock_wait() causes soft lockup with -rt and ieee1394 audio

[Daniel Walker]

On Sun, 2006-07-09 at 13:17 +0200, Pieter Palmers wrote:
> > 
> > I am just posting this for Pieter - all followups should be directed to
> > him.  (I don't even have the hardware to reproduce this)
> > 
> > IIRC the problem could only be reproduced with PREEMPT_RT.  Pieter, can
> > you confirm?
> 
> It can only be reproduced with PREEMPT_RT. And the test kernel is 
> configured with irq threading, I haven't tried it without irq threading.

It's another one of those situations when a userspace real time process
gets stuck in a tight loop waiting for a bit to change. It's similar to
the issue with bit spinlocks, or yield. 

You should be able to reproduce it without PREEMPT_RT but SMP only .

Daniel

status of: tasklet_unlock_wait() causes soft lockup with -rt and ieee1394 audio

[Pieter Palmers]

Dear all,

What is the status with respect to this problem? I see that in the 
current -rt patch the problematic code piece is different. I personally 
haven't tried to reproduce this myself on a more recent kernel, but I 
just got a report from one of our users who experienced the same problem 
with 2.6.19-rt15 and RT preemption (desktop preemption works fine).

Should the latest -rt patches be fixed with respect to this issue? If so 
I'll try and test them, otherwise I omit the effort.

Thanks,

Pieter

Lee Revell wrote:
> Pieter has found this bug in -rt:
> 
> We are experiencing 'soft' deadlocks when running our code (Freebob, 
> i.e. userspace lib for firewire audio) on RT kernels. After a few 
> seconds of system freeze, I get a kernel panic message that signals a soft lockup.
> 
> I've uploaded the photo's of the panic here:
> http://freebob.sourceforge.net/old/img_3378.jpg (without flash)
> http://freebob.sourceforge.net/old/img_3377.jpg (with flash)
> both are of suboptimal quality unfortunately, but all info is readable 
> on one or the other.
> 
> The problems occur when an ISO stream (receive and/or transmit) is shut 
> down in a SCHED_FIFO thread. More precisely when running the freebob 
> jackd backend in real-time mode. And even more precise: they only seem 
> to occur when jackd is shut down. There are no problems when jackd is 
> started without RT scheduling.
> 
> I havent been able to reproduce this with other test programs that are 
> shutting down streams in a SCHED_FIFO thread.
> 
> The problem is not reproducible on non-RT kernels, and it only occurs on those configured for 
> PREEMPT_RT. If I use PREEMPT_DESKTOP, there is no problem. The PREEMPT_DESKTOP setting was the only change between the two tests, all other kernel settings (threaded irq's etc...) were unchanged.
> 
> My tests are performed on 2.6.17-rt1, but the lockups are confirmed for 
> PREEMPT_RT configured kernels 2.6.14 and 2.6.16.
> 
> Some extra information:
> 
> Lee Revell wrote:
> 
>> <...>
>>
>> It seems that the -rt patch changes tasklet_kill:
>>
>> Unpatched 2.6.17:
>>
>> void tasklet_kill(struct tasklet_struct *t)
>> {
>>         if (in_interrupt())
>>                 printk("Attempt to kill tasklet from interrupt\n");
>>
>>         while (test_and_set_bit(TASKLET_STATE_SCHED, &t->state)) {
>>                 do
>>                         yield();
>>                 while (test_bit(TASKLET_STATE_SCHED, &t->state));
>>         }
>>         tasklet_unlock_wait(t);
>>         clear_bit(TASKLET_STATE_SCHED, &t->state);
>> }
>>
>> 2.6.17-rt:
>>
>> void tasklet_kill(struct tasklet_struct *t)
>> {
>>         if (in_interrupt())
>>                 printk("Attempt to kill tasklet from interrupt\n");
>>
>>         while (test_and_set_bit(TASKLET_STATE_SCHED, &t->state)) {
>>                 do                              msleep(1);
>>                 while (test_bit(TASKLET_STATE_SCHED, &t->state));
>>         }
>>         tasklet_unlock_wait(t);
>>         clear_bit(TASKLET_STATE_SCHED, &t->state);
>> }
>>
>> You should ask Ingo & the other -rt developers what the intent of this
>> change was.  Obviously it loops forever waiting for the state bit to
>> change.
> 
> On Thu, 2006-07-06 at 22:14 +0200, Pieter Palmers wrote:
> 
>>> I've put the debugging printk's into tasklet_kill. One interesting 
>>> remark is that now that they are in place, I had to start/stop jackd 
>>> multiple times before deadlock occurs. Without the printk's the machine 
>>> always locked up on the first pass. However I stopped after the first 
>>> lockup, so maybe this is not really significant.
>>>
>>> Anyway, the new tasklet_kill looks like this:
>>>
>>> void tasklet_kill(struct tasklet_struct *t)
>>> {
>>> 	printk("enter tasklet_kill\n");
>>> 	if (in_interrupt())
>>> 		printk("Attempt to kill tasklet from interrupt\n");
>>> 	
>>> 	printk("passed interrupt check\n");
>>>
>>> 	while (test_and_set_bit(TASKLET_STATE_SCHED, &t->state)) {
>>> 		do
>>> 			msleep(1);
>>> 		while (test_bit(TASKLET_STATE_SCHED, &t->state));
>>> 	}
>>> 	printk("passed test_and_set_bit\n");
>>> 	
>>> 	tasklet_unlock_wait(t);
>>> 	printk("passed tasklet_unlock_wait\n");
>>> 	
>>> 	clear_bit(TASKLET_STATE_SCHED, &t->state);
>>> }
>>>
>>> And the last line printed before lockup is:
>>> "passed test_and_set_bit"
>>   
> This makes the change in tasklet_unlock_wait() as the prime suspect for this problem.
> 
> 
> 
> 
> 
> 
> 

Re: status of: tasklet_unlock_wait() causes soft lockup with -rt and ieee1394 audio

[Ingo Molnar]

* Pieter Palmers <pieterp@joow.be> wrote:

> Dear all,
> 
> What is the status with respect to this problem? I see that in the 
> current -rt patch the problematic code piece is different. I 
> personally haven't tried to reproduce this myself on a more recent 
> kernel, but I just got a report from one of our users who experienced 
> the same problem with 2.6.19-rt15 and RT preemption (desktop 
> preemption works fine).
> 
> Should the latest -rt patches be fixed with respect to this issue? If 
> so I'll try and test them, otherwise I omit the effort.

it's not fixed yet. Could you try the patch below?

	Ingo

---
 include/linux/interrupt.h |    6 ++----
 kernel/softirq.c          |   20 ++++++++++++++++++++
 2 files changed, 22 insertions(+), 4 deletions(-)

Index: linux/include/linux/interrupt.h
===================================================================
--- linux.orig/include/linux/interrupt.h
+++ linux/include/linux/interrupt.h
@@ -328,10 +328,8 @@ static inline void tasklet_unlock(struct
 	clear_bit(TASKLET_STATE_RUN, &(t)->state);
 }
 
-static inline void tasklet_unlock_wait(struct tasklet_struct *t)
-{
-	while (test_bit(TASKLET_STATE_RUN, &(t)->state)) { barrier(); }
-}
+extern void tasklet_unlock_wait(struct tasklet_struct *t);
+
 #else
 # define tasklet_trylock(t)		1
 # define tasklet_tryunlock(t)		1
Index: linux/kernel/softirq.c
===================================================================
--- linux.orig/kernel/softirq.c
+++ linux/kernel/softirq.c
@@ -20,6 +20,7 @@
 #include <linux/mm.h>
 #include <linux/notifier.h>
 #include <linux/percpu.h>
+#include <linux/delay.h>
 #include <linux/cpu.h>
 #include <linux/kthread.h>
 #include <linux/rcupdate.h>
@@ -656,6 +657,25 @@ void __init softirq_init(void)
 	open_softirq(HI_SOFTIRQ, tasklet_hi_action, NULL);
 }
 
+#if defined(CONFIG_SMP) || defined(CONFIG_PREEMPT_RT)
+
+void tasklet_unlock_wait(struct tasklet_struct *t)
+{
+	while (test_bit(TASKLET_STATE_RUN, &(t)->state)) {
+		/*
+		 * Hack for now to avoid this busy-loop:
+		 */
+#ifdef CONFIG_PREEMPT_RT
+		msleep(1);
+#else
+		barrier();
+#endif
+	}
+}
+EXPORT_SYMBOL(tasklet_unlock_wait);
+
+#endif
+
 static int ksoftirqd(void * __data)
 {
 	struct sched_param param = { .sched_priority = MAX_USER_RT_PRIO/2 };

Re: status of: tasklet_unlock_wait() causes soft lockup with -rt and ieee1394 audio

[Pieter Palmers]

Ingo Molnar wrote:
> * Pieter Palmers <pieterp@joow.be> wrote:
> 
>> Dear all,
>>
>> What is the status with respect to this problem? I see that in the 
>> current -rt patch the problematic code piece is different. I 
>> personally haven't tried to reproduce this myself on a more recent 
>> kernel, but I just got a report from one of our users who experienced 
>> the same problem with 2.6.19-rt15 and RT preemption (desktop 
>> preemption works fine).
>>
>> Should the latest -rt patches be fixed with respect to this issue? If 
>> so I'll try and test them, otherwise I omit the effort.
> 
> it's not fixed yet. Could you try the patch below?

Ingo,

I couldn't get my laptop booting on 2.6.20-rc3 or 2.6.19, but I passed 
the patch on to one of our users and he reports that it is working (on 
2.6.19-rt15).

Thanks,

Pieter

> 
> 	Ingo
> 
> ---
>  include/linux/interrupt.h |    6 ++----
>  kernel/softirq.c          |   20 ++++++++++++++++++++
>  2 files changed, 22 insertions(+), 4 deletions(-)
> 
> Index: linux/include/linux/interrupt.h
> ===================================================================
> --- linux.orig/include/linux/interrupt.h
> +++ linux/include/linux/interrupt.h
> @@ -328,10 +328,8 @@ static inline void tasklet_unlock(struct
>  	clear_bit(TASKLET_STATE_RUN, &(t)->state);
>  }
>  
> -static inline void tasklet_unlock_wait(struct tasklet_struct *t)
> -{
> -	while (test_bit(TASKLET_STATE_RUN, &(t)->state)) { barrier(); }
> -}
> +extern void tasklet_unlock_wait(struct tasklet_struct *t);
> +
>  #else
>  # define tasklet_trylock(t)		1
>  # define tasklet_tryunlock(t)		1
> Index: linux/kernel/softirq.c
> ===================================================================
> --- linux.orig/kernel/softirq.c
> +++ linux/kernel/softirq.c
> @@ -20,6 +20,7 @@
>  #include <linux/mm.h>
>  #include <linux/notifier.h>
>  #include <linux/percpu.h>
> +#include <linux/delay.h>
>  #include <linux/cpu.h>
>  #include <linux/kthread.h>
>  #include <linux/rcupdate.h>
> @@ -656,6 +657,25 @@ void __init softirq_init(void)
>  	open_softirq(HI_SOFTIRQ, tasklet_hi_action, NULL);
>  }
>  
> +#if defined(CONFIG_SMP) || defined(CONFIG_PREEMPT_RT)
> +
> +void tasklet_unlock_wait(struct tasklet_struct *t)
> +{
> +	while (test_bit(TASKLET_STATE_RUN, &(t)->state)) {
> +		/*
> +		 * Hack for now to avoid this busy-loop:
> +		 */
> +#ifdef CONFIG_PREEMPT_RT
> +		msleep(1);
> +#else
> +		barrier();
> +#endif
> +	}
> +}
> +EXPORT_SYMBOL(tasklet_unlock_wait);
> +
> +#endif
> +
>  static int ksoftirqd(void * __data)
>  {
>  	struct sched_param param = { .sched_priority = MAX_USER_RT_PRIO/2 };
> 

Re: status of: tasklet_unlock_wait() causes soft lockup with -rt and ieee1394 audio

[Pieter Palmers]

Ingo Molnar wrote:
> * Pieter Palmers <pieterp@joow.be> wrote:
> 
>> Dear all,
>>
>> What is the status with respect to this problem? I see that in the 
>> current -rt patch the problematic code piece is different. I 
>> personally haven't tried to reproduce this myself on a more recent 
>> kernel, but I just got a report from one of our users who experienced 
>> the same problem with 2.6.19-rt15 and RT preemption (desktop 
>> preemption works fine).
>>
>> Should the latest -rt patches be fixed with respect to this issue? If 
>> so I'll try and test them, otherwise I omit the effort.
> 
> it's not fixed yet. Could you try the patch below?

I just compiled & installed 2.6.20-rc6-rt2, and I saw that this patch 
was in the -rt2 patch, so I gave real-time preemption a shot. It seems 
to work, I don't experience lockups anymore.

Thanks for the fix,

Pieter