BUG - "scheduling while atomic" on a irq handler (s3c-mci)

Hi everyone,

I am facing a problem while trying to run a rt-patched 3.2.y kernel
with PREEMPT_RT_FULL on a mini2440 board (ARM based s3c2440 SoC) :
whilst a vanilla kernel (with PREEMPT_LL) works like a charm, PREEMPT_RTB and PREEMPT_RT_FULL makes the MMC/SD driver (s3cmci) hang, which result in the kernel waiting indefinitely for the root fs to mount.

I think that the IRQ handling of the driver is somehow disturbed by
the changes made by the RT patch. When using PREEMPT_RTB I can see the following message in the console :

BUG: scheduling while atomic: irq/37-s3c-mci/253/0x00000102
Modules linked in:

Function entered at [<c000e90c>] from [<c029f478>] Function entered at [<c029f478>] from [<c029fc3c>] Function entered at [<c029fc3c>] from [<c00559c0>] Function entered at [<c00559c0>] from [<c01dd4c8>] Function entered at [<c01dd4c8>] from [<c0024a0c>] Function entered at [<c0024a0c>] from [<c0024d9c>] Function entered at [<c0024d9c>] from [<c0024fe8>] Function entered at [<c0024fe8>] from [<c0025140>] Function entered at [<c0025140>] from [<c00549f0>] Function entered at [<c00549f0>] from [<c00547c4>] Function entered at [<c00547c4>] from [<c0039954>] Function entered at [<c0039954>] from [<c000a120>]

When I run the kernel under Qemu, debug through gdb and put a
breakpoint on unwind_backtace the details of the previous backtrace is :

#0  unwind_backtrace (regs=0x0, tsk=0x0) at arch/arm/kernel/unwind.c:409
#1  0xc029f478 in schedule_debug (prev=<optimized out>) at kernel/sched.c:4357
#2  __schedule () at kernel/sched.c:4537
#3  0xc029fc3c in schedule () at kernel/sched.c:4625
#4  0xc00559c0 in synchronize_irq (irq=<optimized out>) at

kernel/irq/manage.c:73
Backtrace stopped: previous frame inner to this frame (corrupt stack?)

I don't see the "bug" message with PREEMPT_RT_FULL, the kernel just
hang waiting for the rootfs. The problem did not occur in the 2.6.y tree AFAIK.

I'd like to investigate more and fix the s3cmci driver but I don't
know where to begin, could someone give me some hints on what should be done/not be done for a rt patch compliant device driver/irq handler ?

Regards,
Christophe Huriaux

Hi Christophe,

If you enable CONFIG_KALLSYMS you get a more usable backtrace. Alternatively you can use

	$CROSS_COMPILE-addr2line -e vmlinux 0xc000e90c

to get the file and line that resulted in the code at that address.

My guess is that for PREEMPT_RT_FULL the printk just doesn't make it to your console driver because the data would only be given to it when the atomic block is done.

Best regards
Uwe

Pengutronix e.K.                           | Uwe Kleine-König            |
Industrial Linux Solutions                 | http://www.pengutronix.de/  |
--
To unsubscribe from this list: send the line "unsubscribe linux-rt-users" in
the body of a message to [email protected]
More majordomo info at  http://vger.kernel.org/majordomo-info.html

2012/5/9 Uwe Kleine-König <[email protected]>:

Thanks, I was wondering which config option would enable that. The
complete backtrace is much more usable :

BUG: scheduling while atomic: irq/37-s3c-mci/253/0x00000102
Modules linked in:
[<c000e9fc>] (unwind_backtrace+0x0/0x12c) from [<c029b82c>]
(__schedule+0x58/0x2c0)
[<c029b82c>] (__schedule+0x58/0x2c0) from [<c029bc10>] (schedule+0x8c/0xb0)
[<c029bc10>] (schedule+0x8c/0xb0) from [<c0055614>] (synchronize_irq+0xbc/0xd8)
[<c0055614>] (synchronize_irq+0xbc/0xd8) from [<c01db6b0>]
(pio_tasklet+0x34/0x11c)
[<c01db6b0>] (pio_tasklet+0x34/0x11c) from [<c0024914>]
(__tasklet_action+0x68/0x80)
[<c0024914>] (__tasklet_action+0x68/0x80) from [<c0024ca4>]
(__do_softirq+0x88/0x130)
[<c0024ca4>] (__do_softirq+0x88/0x130) from [<c0024ef0>] (do_softirq+0x48/0x54)
[<c0024ef0>] (do_softirq+0x48/0x54) from [<c0025048>]
(local_bh_enable+0x8c/0xc0)
[<c0025048>] (local_bh_enable+0x8c/0xc0) from [<c0054678>]
(irq_forced_thread_fn+0x4c/0x54)
[<c0054678>] (irq_forced_thread_fn+0x4c/0x54) from [<c0054454>]
(irq_thread+0xa0/0x1c0)
[<c0054454>] (irq_thread+0xa0/0x1c0) from [<c0038628>] (kthread+0x84/0x8c)
[<c0038628>] (kthread+0x84/0x8c) from [<c000a100>] (kernel_thread_exit+0x0/0x8)

Indeed : after tracing printk calls in GDB while in PREEMPT_RT_FULL
I can see that there is a lot more data sent than what the serial driver handles.

I'm able to fix this problem by replacing disable_irq() calls by
disable_irq_nosync() in s3cmci_enable_irq() and s3cmci_disable_irq() (see patch below), which does not trigger a schedule. I don't see any problem so far (at least I can boot !).

From: Christophe Huriaux <[email protected]>
Subject: [PATCH] Fix scheduling while atomic bug in pio_tasklet

---
 drivers/mmc/host/s3cmci.c |    8 ++++++++
 1 file changed, 8 insertions(+)

index 720f993..9978ad6 100644
@@ -329,7 +329,11 @@ static void s3cmci_enable_irq(struct s3cmci_host

*host, bool more)

                if (enable)
                        enable_irq(host->irq);
                else
+#ifdef CONFIG_PREEMPT_RT_BASE
+                       disable_irq_nosync(host->irq);
+#else
                        disable_irq(host->irq);
+#endif
        }

        local_irq_restore(flags);

@@ -350,7 +354,11 @@ static void s3cmci_disable_irq(struct s3cmci_host *host, bool transfer)

        if (transfer && host->irq_state) {
                host->irq_state = false;
+#ifdef CONFIG_PREEMPT_RT_BASE
+               disable_irq_nosync(host->irq);
+#else
                disable_irq(host->irq);
+#endif
        }

        local_irq_restore(flags);

1.7.9.5


Regards,
Christophe Huriaux
--
To unsubscribe from this list: send the line "unsubscribe linux-rt-users" in
the body of a message to [email protected]
More majordomo info at  http://vger.kernel.org/majordomo-info.html

What happens if you instead convert the local_irq_save/restore() to local_irq_save_nort/restore_nort()?

Does that work too?

-- Steve

Actually I don't think this is a -rt issue, you could also trigger this warning with vanilla if you boot your kernel with 'threadirqs'.

Could you pleaes try the follow patch?

Thanks,
Yong

---
From: Yong Zhang <[email protected]>
Date: Sun, 20 May 2012 12:56:46 +0800
Subject: [PATCH] genirq: don't sync irq thread if current happen to be the very irq thread

Christophe reported against -rt:

BUG: scheduling while atomic: irq/37-s3c-mci/253/0x00000102
Modules linked in:
[<c000e9fc>] (unwind_backtrace+0x0/0x12c) from [<c029b82c>] (__schedule+0x58/0x2c0)
[<c029b82c>] (__schedule+0x58/0x2c0) from [<c029bc10>] (schedule+0x8c/0xb0)
[<c029bc10>] (schedule+0x8c/0xb0) from [<c0055614>] (synchronize_irq+0xbc/0xd8)
[<c0055614>] (synchronize_irq+0xbc/0xd8) from [<c01db6b0>] (pio_tasklet+0x34/0x11c)
[<c01db6b0>] (pio_tasklet+0x34/0x11c) from [<c0024914>] (__tasklet_action+0x68/0x80)
[<c0024914>] (__tasklet_action+0x68/0x80) from [<c0024ca4>] (__do_softirq+0x88/0x130)
[<c0024ca4>] (__do_softirq+0x88/0x130) from [<c0024ef0>] (do_softirq+0x48/0x54)
[<c0024ef0>] (do_softirq+0x48/0x54) from [<c0025048>] (local_bh_enable+0x8c/0xc0)
[<c0025048>] (local_bh_enable+0x8c/0xc0) from [<c0054678>] (irq_forced_thread_fn+0x4c/0x54)
[<c0054678>] (irq_forced_thread_fn+0x4c/0x54) from [<c0054454>] (irq_thread+0xa0/0x1c0)
[<c0054454>] (irq_thread+0xa0/0x1c0) from [<c0038628>] (kthread+0x84/0x8c)
[<c0038628>] (kthread+0x84/0x8c) from [<c000a100>] (kernel_thread_exit+0x0/0x8)

Whe looking at this issue, I find that there is a typical deadlock scenario with forced treaded irq,

irq_forced_thread_fn()

  local_bh_enable();
    do_softirq();
      disable_irq();
        synchronize_irq();
          wait_event();
          /*DEAD*/

Cure it by unsync if current happen to be the very irq thread.

---
 kernel/irq/manage.c |    9 +++++++++
 1 files changed, 9 insertions(+), 0 deletions(-)

index 89a3ea8..d5b96e7 100644
@@ -41,6 +41,7 @@ early_param("threadirqs", setup_forced_irqthreads);
 void synchronize_irq(unsigned int irq)
 {
 	struct irq_desc *desc = irq_to_desc(irq);
+	struct irqaction *action = desc->action;
 	bool inprogress;
 
 	if (!desc)

@@ -67,7 +68,15 @@ void synchronize_irq(unsigned int irq)
 	/*
 	 * We made sure that no hardirq handler is running. Now verify
 	 * that no threaded handlers are active.
+	 * But for theaded irq, we don't sync if current happens to be
+	 * the irq thread; otherwise we could deadlock.
 	 */
+	while (action) {
+		if (action->thread && action->thread == current)
+			return;
+		action = action->next;
+	}
+
 	wait_event(desc->wait_for_threads, !atomic_read(&desc->threads_active));
 }
 EXPORT_SYMBOL(synchronize_irq);

1.7.1

You meant dereferencing *desc :)

Ah, yes :)

Yes.

I'll reconsider this issue and try to find the simpler way.

Thanks,
Yong