mtdoops and non pre-emptible kernel

mtdoops and non pre-emptible kernel

[Matthew Lear]

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

Hello,

I'm trying to use the mtd oops feature on a non pre-emptible m68k
coldfire Linux kernel. Problem is, there is nothing being written to
flash upon a kernel panic. I'm passing the correct syntax on the command
line and I can see the kernel messages indicating that everything is ok, ie:

/ # dmesg | grep -i mtd
[    0.000000] Kernel command line: console=ttyS0,115200 ip=dhcp
root=/dev/nfs nfsroot=192.168.0.2:/home/matt/nfs/evb/rootfs/ rw
mtdparts=physmap-flash.0:4M@0x80000(kernel)ro,5M@0x480000(r
amdisk),-@0x980000(writeable) console=ttyMTD2
[    0.336920] console [ttyMTD2] enabled
[    0.933655] 3 cmdlinepart partitions found on MTD device physmap-flash.0
[    0.940745] Creating 3 MTD partitions on "physmap-flash.0":
[    0.951893] mtd: Giving out device 0 to kernel
[    0.965760] mtd: Giving out device 1 to ramdisk
[    0.979124] mtd: Giving out device 2 to writeable
[    0.993942] mtdoops: Ready 8, 9 (no erase)
[    0.993979] mtdoops: Attached to MTD device 2

The issue appears to be that the call to schedule_work() in
mtdoops_console_sync() does not result in mtdoops_workfunc_write() being
invoked to perform the flash write.

I understand that there is only a very small window in which to actually
flush the buffer to flash (involving a spinlock and testing
oops_in_progress). However, from what I can tell, on a non pre-emptible
kernel, after panic() does it's business of calling bust_spinlocks(),
which calls console_unblank(), which calls mtdoops_console_sync(), which
calls schedule_work(), there is no way [certainly that I can see] that
the system can context switch to the worker thread in order to invoke
the routine that actually writes to flash.

The only way I have been able to get the flash to be written to upon
panic is to make the following change:

diff --git a/drivers/mtd/mtdoops.c b/drivers/mtd/mtdoops.c
index 1a6b3be..2d734e2 100644
--- a/drivers/mtd/mtdoops.c
+++ b/drivers/mtd/mtdoops.c
@@ -335,7 +335,7 @@ static void mtdoops_console_sync(void)
                /* Interrupt context, we're going to panic so try and log */
                mtdoops_write(cxt, 1);
        else
-               schedule_work(&cxt->work_write);
+               mtdoops_write(cxt, 0);
 }

 static void

I can pull out the logs just fine in user space using oopslog, courtesy
of Mr Purdie.

I can replicate the same situation (worker thread not executing the
registered scheduled work routine) on my system with a simple kernel
module (attached). Without the call to schedule, the system does not
panic. In the case of the attached example, this is not surprising since
there is nothing to force a context switch. The kernel sits in the loop
forever and will warn about a soft lock up (if this feature is enabled).

I have tried invoking schedule() immediately after schedule_work() in
mtdoops_console_sync(). However this still results in flash not being
written to when there is a panic. I realise that now there are of course
other factors at play which could explain why the flash never gets
written to, (specifically related to scheduling, eg thread time slices,
quantums etc), but I wanted to point out that there certainly appears to
be a couple of cases in mtdoops.c where there should be calls to
schedule() after calls to schedule_work() - only there aren't.

I don't mean to criticise the code :-) I'm an avid user of open source,
but I'd be interested if the mtd oops feature works reliably on other
non pre-emptive kernels.

Thoughts? Any feedback much appreciated.

Best regards,
--  Matt

[-- Attachment #2: work.c --]
[-- Type: text/x-csrc, Size: 757 bytes --]

#include <linux/init.h>
#include <linux/module.h>
#include <linux/workqueue.h>
#include <linux/delay.h>
#include <linux/sched.h>

MODULE_LICENSE("foo");

static struct work_struct mywork;

static void mywork_func(struct work_struct *work)
{
   panic("Adios muchachos");
}

static int myinit(void)
{
   int i;
   printk(KERN_ALERT "myinit ->\n");

   INIT_WORK(&mywork, mywork_func);

   schedule_work(&mywork);
   schedule();

   /* This loop will hang non-premptible kernels and the worker func above
    * will not be executed without the above call to schedule. */
   for (i = 0;;) {
      mdelay(1);
      i++;
   }

   return 0;
}

static void myexit(void)
{
   printk(KERN_ALERT "<- myinit\n");
   return;
}

module_init(myinit);
module_exit(myexit);

Re: mtdoops and non pre-emptible kernel

[Richard Purdie]

On Wed, 2009-08-26 at 18:41 +0100, Matthew Lear wrote:
> I'm trying to use the mtd oops feature on a non pre-emptible m68k
> coldfire Linux kernel. Problem is, there is nothing being written to
> flash upon a kernel panic. I'm passing the correct syntax on the command
> line and I can see the kernel messages indicating that everything is ok, ie:
> 
> / # dmesg | grep -i mtd
> [    0.000000] Kernel command line: console=ttyS0,115200 ip=dhcp
> root=/dev/nfs nfsroot=192.168.0.2:/home/matt/nfs/evb/rootfs/ rw
> mtdparts=physmap-flash.0:4M@0x80000(kernel)ro,5M@0x480000(r
> amdisk),-@0x980000(writeable) console=ttyMTD2
> [    0.336920] console [ttyMTD2] enabled
> [    0.933655] 3 cmdlinepart partitions found on MTD device physmap-flash.0
> [    0.940745] Creating 3 MTD partitions on "physmap-flash.0":
> [    0.951893] mtd: Giving out device 0 to kernel
> [    0.965760] mtd: Giving out device 1 to ramdisk
> [    0.979124] mtd: Giving out device 2 to writeable
> [    0.993942] mtdoops: Ready 8, 9 (no erase)
> [    0.993979] mtdoops: Attached to MTD device 2
> 
> The issue appears to be that the call to schedule_work() in
> mtdoops_console_sync() does not result in mtdoops_workfunc_write() being
> invoked to perform the flash write.

If you've looked at that code you'll see there are two ways the code can
go. It tries to detect if it can still schedule and if so it will use
the workqueue, else it will call the write function directly.

If the MTD device has support it will then use any panic_write function
to bypass any other scheduling the driver may do.

Digging through past emails, there was the fragment of code below that I
think was required to catch certain oops too. This wasn't acceptable to
mainline at the time, I don't know if its still needed or still not
acceptable.

Cheers,

Richard

diff --git a/lib/bust_spinlocks.c b/lib/bust_spinlocks.c
--- a/lib/bust_spinlocks.c
+++ b/lib/bust_spinlocks.c
@@ -12,7 +12,7 @@
 #include <linux/tty.h>
 #include <linux/wait.h>
 #include <linux/vt_kern.h>
-
+#include <linux/console.h>
 
 void __attribute__((weak)) bust_spinlocks(int yes)
 {
@@ -22,6 +22,7 @@ void __attribute__((weak)) bust_spinlocks(int yes)
 #ifdef CONFIG_VT
               unblank_screen();
 #endif
+              console_unblank();
               oops_in_progress = 0;
               wake_up_klogd();
       }

Re: mtdoops and non pre-emptible kernel

[Matthew Lear]

> On Wed, 2009-08-26 at 18:41 +0100, Matthew Lear wrote:
>> I'm trying to use the mtd oops feature on a non pre-emptible m68k
>> coldfire Linux kernel. Problem is, there is nothing being written to
>> flash upon a kernel panic. I'm passing the correct syntax on the command
>> line and I can see the kernel messages indicating that everything is ok,
>> ie:
>>
>> / # dmesg | grep -i mtd
>> [    0.000000] Kernel command line: console=ttyS0,115200 ip=dhcp
>> root=/dev/nfs nfsroot=192.168.0.2:/home/matt/nfs/evb/rootfs/ rw
>> mtdparts=physmap-flash.0:4M@0x80000(kernel)ro,5M@0x480000(r
>> amdisk),-@0x980000(writeable) console=ttyMTD2
>> [    0.336920] console [ttyMTD2] enabled
>> [    0.933655] 3 cmdlinepart partitions found on MTD device
>> physmap-flash.0
>> [    0.940745] Creating 3 MTD partitions on "physmap-flash.0":
>> [    0.951893] mtd: Giving out device 0 to kernel
>> [    0.965760] mtd: Giving out device 1 to ramdisk
>> [    0.979124] mtd: Giving out device 2 to writeable
>> [    0.993942] mtdoops: Ready 8, 9 (no erase)
>> [    0.993979] mtdoops: Attached to MTD device 2
>>
>> The issue appears to be that the call to schedule_work() in
>> mtdoops_console_sync() does not result in mtdoops_workfunc_write() being
>> invoked to perform the flash write.
>
> If you've looked at that code you'll see there are two ways the code can
> go. It tries to detect if it can still schedule and if so it will use
> the workqueue, else it will call the write function directly.
>
> If the MTD device has support it will then use any panic_write function
> to bypass any other scheduling the driver may do.
>
> Digging through past emails, there was the fragment of code below that I
> think was required to catch certain oops too. This wasn't acceptable to
> mainline at the time, I don't know if its still needed or still not
> acceptable.
>
> Cheers,
>
> Richard
>
> diff --git a/lib/bust_spinlocks.c b/lib/bust_spinlocks.c
> --- a/lib/bust_spinlocks.c
> +++ b/lib/bust_spinlocks.c
> @@ -12,7 +12,7 @@
>  #include <linux/tty.h>
>  #include <linux/wait.h>
>  #include <linux/vt_kern.h>
> -
> +#include <linux/console.h>
>
>  void __attribute__((weak)) bust_spinlocks(int yes)
>  {
> @@ -22,6 +22,7 @@ void __attribute__((weak)) bust_spinlocks(int yes)
>  #ifdef CONFIG_VT
>                unblank_screen();
>  #endif
> +              console_unblank();
>                oops_in_progress = 0;
>                wake_up_klogd();
>        }
>
Thanks for the reply, Richard. The change above is certainly in the 2.6.29
kernel that I'm running and it's also in the current linux-m68k git, so I
assume it made mainline some time ago.

In any case, yes I saw the two paths the code can go, ie if the mtd
device's panic_write() is available and we're in interrupt context then
use the panic_write function to write to flash, else use the work queue.
The path that my scenario takes is always the latter but the write in
context of the work queue never happens.

If this is because of the small window in which to perform the write and
there are other factors coming into play involving scheduling then
obviously that's not a direct issue for the mtdoops code.

However, the call to mtdoops_console_sync() (which causes the flash write
to be initiated from console_unblank() for the ttyMTD console device) is
eventually followed by the panic routine spinning in a tight loop with an
mdelay(1). There doesn't appear to be anywhere in this path where
schedule() is invoked. Because of running a non pre-emptible kernel, there
is no way, certainly that I can see, that a context can switch can happen
to allow the jobs in the work queue to be run without at least calling
schedule() after calling schedule_work() from within
mtdoops_console_sync().

Maybe I've missed something :-) but calling schedule() after
schedule_work() certainly seems to be the correct approach to at least
allow the code to do what it's trying to do, especially on non
pre-emptible kernels.

Cheers,
--  Matt

Re: mtdoops and non pre-emptible kernel

[Richard Purdie]

On Thu, 2009-08-27 at 09:59 +0100, Matthew Lear wrote: 
> In any case, yes I saw the two paths the code can go, ie if the mtd
> device's panic_write() is available and we're in interrupt context then
> use the panic_write function to write to flash, else use the work queue.
> The path that my scenario takes is always the latter but the write in
> context of the work queue never happens.
> 
> If this is because of the small window in which to perform the write and
> there are other factors coming into play involving scheduling then
> obviously that's not a direct issue for the mtdoops code.
> 
> However, the call to mtdoops_console_sync() (which causes the flash write
> to be initiated from console_unblank() for the ttyMTD console device) is
> eventually followed by the panic routine spinning in a tight loop with an
> mdelay(1). There doesn't appear to be anywhere in this path where
> schedule() is invoked. Because of running a non pre-emptible kernel, there
> is no way, certainly that I can see, that a context can switch can happen
> to allow the jobs in the work queue to be run without at least calling
> schedule() after calling schedule_work() from within
> mtdoops_console_sync().
> 
> Maybe I've missed something :-) but calling schedule() after
> schedule_work() certainly seems to be the correct approach to at least
> allow the code to do what it's trying to do, especially on non
> pre-emptible kernels.

That isn't the right solution since calling schedule() is not something
allowed at that point in the code, particularly in the middle of a
kernel panic. We really need to detect that we're about to head into the
panic spining loop and then call the write function directly. How we do
that I'm not so sure without going into the code in more detail. I
suspect something has subtly changed in the kernel meaning that
particular circumstances no longer works :/

Cheers,

Richard

Re: mtdoops and non pre-emptible kernel

[Matthew Lear]

> On Thu, 2009-08-27 at 09:59 +0100, Matthew Lear wrote:
>> In any case, yes I saw the two paths the code can go, ie if the mtd
>> device's panic_write() is available and we're in interrupt context then
>> use the panic_write function to write to flash, else use the work queue.
>> The path that my scenario takes is always the latter but the write in
>> context of the work queue never happens.
>>
>> If this is because of the small window in which to perform the write and
>> there are other factors coming into play involving scheduling then
>> obviously that's not a direct issue for the mtdoops code.
>>
>> However, the call to mtdoops_console_sync() (which causes the flash
>> write
>> to be initiated from console_unblank() for the ttyMTD console device) is
>> eventually followed by the panic routine spinning in a tight loop with
>> an
>> mdelay(1). There doesn't appear to be anywhere in this path where
>> schedule() is invoked. Because of running a non pre-emptible kernel,
>> there
>> is no way, certainly that I can see, that a context can switch can
>> happen
>> to allow the jobs in the work queue to be run without at least calling
>> schedule() after calling schedule_work() from within
>> mtdoops_console_sync().
>>
>> Maybe I've missed something :-) but calling schedule() after
>> schedule_work() certainly seems to be the correct approach to at least
>> allow the code to do what it's trying to do, especially on non
>> pre-emptible kernels.
>
> That isn't the right solution since calling schedule() is not something
> allowed at that point in the code, particularly in the middle of a
> kernel panic. We really need to detect that we're about to head into the
> panic spining loop and then call the write function directly. How we do
> that I'm not so sure without going into the code in more detail. I
> suspect something has subtly changed in the kernel meaning that
> particular circumstances no longer works :/
>
That's fair enough. I suppose a possible solution would be to do what I've
done locally for testing, ie:

diff --git a/drivers/mtd/mtdoops.c b/drivers/mtd/mtdoops.c
index 1a6b3be..2d734e2 100644
--- a/drivers/mtd/mtdoops.c
+++ b/drivers/mtd/mtdoops.c
@@ -335,7 +335,7 @@ static void mtdoops_console_sync(void)
                /* Interrupt context, we're going to panic so try and log */
                mtdoops_write(cxt, 1);
        else
-               schedule_work(&cxt->work_write);
+               mtdoops_write(cxt, 0);
 }

 static void

Obviously this performs the flash write in the same context as that of
panic() and negates the need for the registration and usage of the work
routine, so it would simplify things. However, this would/could effect
what happens during a panic. Clearly the thought behind writing to flash
asynchronously was deemed a requirement.

Perhaps it does need another look and some testing on pre-empt and non
pre-empt kernels just to get a feel for if the mtdoops code is still
working as intended. I know that our kernel will be running with the above
patch applied as it's the only way I can reliably log to flash upon panic.

Cheers,
--  Matt

Re: mtdoops and non pre-emptible kernel

[Richard Purdie]

On Thu, 2009-08-27 at 11:30 +0100, Matthew Lear wrote:
> That's fair enough. I suppose a possible solution would be to do what I've
> done locally for testing, ie:
> 
> diff --git a/drivers/mtd/mtdoops.c b/drivers/mtd/mtdoops.c
> index 1a6b3be..2d734e2 100644
> --- a/drivers/mtd/mtdoops.c
> +++ b/drivers/mtd/mtdoops.c
> @@ -335,7 +335,7 @@ static void mtdoops_console_sync(void)
>                 /* Interrupt context, we're going to panic so try and log */
>                 mtdoops_write(cxt, 1);
>         else
> -               schedule_work(&cxt->work_write);
> +               mtdoops_write(cxt, 0);
>  }

I just refreshed my memory a bit. I'd guess your mtd driver doesn't have
a panic_write function which is highly desirable for this kind of use.

How about some code like this?:

	if (mtd->panic_write && in_interrupt())
		/* Interrupt context, we're going to panic so try and log */
		mtdoops_write(cxt, 1);
	else if (in_interrupt())
		/* Interrupt context but with no panic write function */
                /* We're going to crash anyway so we may as well try and log */
		mtdoops_write(cxt, 0);
	else
		schedule_work(&cxt->work_write);

Cheers,

Richard

Re: mtdoops and non pre-emptible kernel

[Matthew Lear]

> On Thu, 2009-08-27 at 11:30 +0100, Matthew Lear wrote:
>> That's fair enough. I suppose a possible solution would be to do what
>> I've
>> done locally for testing, ie:
>>
>> diff --git a/drivers/mtd/mtdoops.c b/drivers/mtd/mtdoops.c
>> index 1a6b3be..2d734e2 100644
>> --- a/drivers/mtd/mtdoops.c
>> +++ b/drivers/mtd/mtdoops.c
>> @@ -335,7 +335,7 @@ static void mtdoops_console_sync(void)
>>                 /* Interrupt context, we're going to panic so try and
>> log */
>>                 mtdoops_write(cxt, 1);
>>         else
>> -               schedule_work(&cxt->work_write);
>> +               mtdoops_write(cxt, 0);
>>  }
>
> I just refreshed my memory a bit. I'd guess your mtd driver doesn't have
> a panic_write function which is highly desirable for this kind of use.
>
> How about some code like this?:
>
> 	if (mtd->panic_write && in_interrupt())
> 		/* Interrupt context, we're going to panic so try and log */
> 		mtdoops_write(cxt, 1);
> 	else if (in_interrupt())
> 		/* Interrupt context but with no panic write function */
>                 /* We're going to crash anyway so we may as well try and
> log */
> 		mtdoops_write(cxt, 0);
> 	else
> 		schedule_work(&cxt->work_write);
>

Hi Richard. Unfortunately, in all the circumstances that I've been using
to force a panic (insmod a ko which just panics, provide some obviously
wrong boot args on the command line etc), I never seem to be in interrupt
context when the mtdoops code syncs and tries to write to flash, ie:

if (mtd->panic_write)
  printk(KERN_ALERT "we've got panic_write()\n");
else if (in_interrupt())
  printk(KERN_ALERT "we're in interrupt\n");
else
printk(KERN_ALERT "we'll just schedule work\n");

always prints the last message (although I know that my mtd driver doesn't
have a panic_write function so the first was never going to appear). So,
even if I have a panic_write function, it would never get called as the
initial condition would be false.

I agree that your code snippet above makes sense and should probably be
put forward for integration, though :-)

I'm still a bit stuck with the fact that I'm panicking, I'm not in
interrupt context but the jobs in the work queue don't get scheduled to
run because nothing can force a context switch so my flash never gets
written to.

I believe that it is a correct guideline to call schedule() after calling
schedule_work(). Is this a true statement? However, as you say, in a panic
situation this is undesirable. That said though, I partially do think that
the mtd console unblank function should adhere to this behaviour and call
schedule(). What I'm trying to say is, just because the mtd console
unblank is called from panic() isn't this breaking the guidelines on the
usage of schedule_work() (ie not calling schedule()afterwards) and making
assumptions about what else is going on in the system?

Cheers,
--  Matt

Re: mtdoops and non pre-emptible kernel

[Matthew Lear]

Matthew Lear wrote:
>> On Thu, 2009-08-27 at 11:30 +0100, Matthew Lear wrote:
>>> That's fair enough. I suppose a possible solution would be to do what
>>> I've
>>> done locally for testing, ie:
>>>
>>> diff --git a/drivers/mtd/mtdoops.c b/drivers/mtd/mtdoops.c
>>> index 1a6b3be..2d734e2 100644
>>> --- a/drivers/mtd/mtdoops.c
>>> +++ b/drivers/mtd/mtdoops.c
>>> @@ -335,7 +335,7 @@ static void mtdoops_console_sync(void)
>>>                 /* Interrupt context, we're going to panic so try and
>>> log */
>>>                 mtdoops_write(cxt, 1);
>>>         else
>>> -               schedule_work(&cxt->work_write);
>>> +               mtdoops_write(cxt, 0);
>>>  }
>> I just refreshed my memory a bit. I'd guess your mtd driver doesn't have
>> a panic_write function which is highly desirable for this kind of use.
>>
>> How about some code like this?:
>>
>> 	if (mtd->panic_write && in_interrupt())
>> 		/* Interrupt context, we're going to panic so try and log */
>> 		mtdoops_write(cxt, 1);
>> 	else if (in_interrupt())
>> 		/* Interrupt context but with no panic write function */
>>                 /* We're going to crash anyway so we may as well try and
>> log */
>> 		mtdoops_write(cxt, 0);
>> 	else
>> 		schedule_work(&cxt->work_write);
>>
> 
> Hi Richard. Unfortunately, in all the circumstances that I've been using
> to force a panic (insmod a ko which just panics, provide some obviously
> wrong boot args on the command line etc), I never seem to be in interrupt
> context when the mtdoops code syncs and tries to write to flash, ie:
> 
> if (mtd->panic_write)
>   printk(KERN_ALERT "we've got panic_write()\n");
> else if (in_interrupt())
>   printk(KERN_ALERT "we're in interrupt\n");
> else
> printk(KERN_ALERT "we'll just schedule work\n");
> 
> always prints the last message (although I know that my mtd driver doesn't
> have a panic_write function so the first was never going to appear). So,
> even if I have a panic_write function, it would never get called as the
> initial condition would be false.
> 
> I agree that your code snippet above makes sense and should probably be
> put forward for integration, though :-)
> 
> I'm still a bit stuck with the fact that I'm panicking, I'm not in
> interrupt context but the jobs in the work queue don't get scheduled to
> run because nothing can force a context switch so my flash never gets
> written to.
> 
> I believe that it is a correct guideline to call schedule() after calling
> schedule_work(). Is this a true statement? However, as you say, in a panic
> situation this is undesirable. That said though, I partially do think that
> the mtd console unblank function should adhere to this behaviour and call
> schedule(). What I'm trying to say is, just because the mtd console
> unblank is called from panic() isn't this breaking the guidelines on the
> usage of schedule_work() (ie not calling schedule()afterwards) and making
> assumptions about what else is going on in the system?
> 
> Cheers,
> --  Matt
> 

Hi Richard - I plan to raise this issue in the kernel bug tracker to
hopefully open up discussion with people who are much more involved with
recent kernel changes than I. The idea being that there may have been
changes may have effected the way that the mtd oops code behaves during
a panic. As the code stands at the moment it does not seem to work
correctly for me. Obviously if this is due to other aspects of my system
being configured incorrectly then that's absolutely fine and I'll ensure
these are resolved :-) I think this is the right thing to do.
Cheers,
--  Matt