[PATCH] pstore: change mutex locking to spin_locks

[PATCH] pstore: change mutex locking to spin_locks

[Don Zickus]

pstore was using mutex locking to protect read/write access to the
backend plug-ins.  This causes problems when pstore is executed in
an NMI context through panic() -> kmsg_dump().

This patch changes the mutex to a spin_lock_irqsave then also checks to
see if we are in an NMI context.  If we are in an NMI and can't get the
lock, just print a message stating that and blow by the locking.

All this is probably a hack around the bigger locking problem but it
solves my current situation of trying to sleep in an NMI context.

Tested by loading the lkdtm module and executing a HARDLOCKUP which
will cause the machine to panic inside the nmi handler.

Signed-off-by: Don Zickus <dzickus@redhat.com>
---
 drivers/acpi/apei/erst.c |    2 +-
 fs/pstore/platform.c     |   28 ++++++++++++++++++++++------
 include/linux/pstore.h   |    2 +-
 3 files changed, 24 insertions(+), 8 deletions(-)

diff --git a/drivers/acpi/apei/erst.c b/drivers/acpi/apei/erst.c
index e6cef8e..3d9c2a3 100644
--- a/drivers/acpi/apei/erst.c
+++ b/drivers/acpi/apei/erst.c
@@ -1155,7 +1155,7 @@ static int __init erst_init(void)
 		goto err_release_erange;
 
 	buf = kmalloc(erst_erange.size, GFP_KERNEL);
-	mutex_init(&erst_info.buf_mutex);
+	spin_lock_init(&erst_info.buf_lock);
 	if (buf) {
 		erst_info.buf = buf + sizeof(struct cper_pstore_record);
 		erst_info.bufsize = erst_erange.size -
diff --git a/fs/pstore/platform.c b/fs/pstore/platform.c
index f2c3ff2..53ba00b 100644
--- a/fs/pstore/platform.c
+++ b/fs/pstore/platform.c
@@ -27,6 +27,7 @@
 #include <linux/string.h>
 #include <linux/slab.h>
 #include <linux/uaccess.h>
+#include <linux/hardirq.h>
 
 #include "internal.h"
 
@@ -68,13 +69,21 @@ static void pstore_dump(struct kmsg_dumper *dumper,
 	char		*dst, *why;
 	u64		id;
 	int		hsize, part = 1;
+	unsigned long	flags = 0;
+	int 		is_locked = 0;
 
 	if (reason < ARRAY_SIZE(reason_str))
 		why = reason_str[reason];
 	else
 		why = "Unknown";
 
-	mutex_lock(&psinfo->buf_mutex);
+	if (in_nmi()) {
+		is_locked = spin_trylock(&psinfo->buf_lock);
+		if (!is_locked)
+			pr_err("pstore dump routine blocked in NMI, may corrupt error record\n");
+	} else {
+		spin_lock_irqsave(&psinfo->buf_lock, flags);
+	}
 	oopscount++;
 	while (total < kmsg_bytes) {
 		dst = psinfo->buf;
@@ -103,7 +112,12 @@ static void pstore_dump(struct kmsg_dumper *dumper,
 		l2 -= l2_cpy;
 		total += l1_cpy + l2_cpy;
 	}
-	mutex_unlock(&psinfo->buf_mutex);
+	if (in_nmi()) {
+		if (is_locked)
+			spin_unlock(&psinfo->buf_lock);
+	} else {
+		spin_unlock_irqrestore(&psinfo->buf_lock, flags);
+	}
 }
 
 static struct kmsg_dumper pstore_dumper = {
@@ -157,11 +171,12 @@ void pstore_get_records(void)
 	enum pstore_type_id	type;
 	struct timespec		time;
 	int			failed = 0, rc;
+	unsigned long		flags;
 
 	if (!psi)
 		return;
 
-	mutex_lock(&psinfo->buf_mutex);
+	spin_lock_irqsave(&psinfo->buf_lock, flags);
 	rc = psi->open(psi);
 	if (rc)
 		goto out;
@@ -173,7 +188,7 @@ void pstore_get_records(void)
 	}
 	psi->close(psi);
 out:
-	mutex_unlock(&psinfo->buf_mutex);
+	spin_unlock_irqrestore(&psinfo->buf_lock, flags);
 
 	if (failed)
 		printk(KERN_WARNING "pstore: failed to load %d record(s) from '%s'\n",
@@ -187,6 +202,7 @@ out:
 int pstore_write(enum pstore_type_id type, char *buf, size_t size)
 {
 	u64	id;
+	unsigned long flags;
 
 	if (!psinfo)
 		return -ENODEV;
@@ -194,13 +210,13 @@ int pstore_write(enum pstore_type_id type, char *buf, size_t size)
 	if (size > psinfo->bufsize)
 		return -EFBIG;
 
-	mutex_lock(&psinfo->buf_mutex);
+	spin_lock_irqsave(&psinfo->buf_lock, flags);
 	memcpy(psinfo->buf, buf, size);
 	id = psinfo->write(type, size);
 	if (pstore_is_mounted())
 		pstore_mkfile(PSTORE_TYPE_DMESG, psinfo->name, id, psinfo->buf,
 			      size, CURRENT_TIME, psinfo->erase);
-	mutex_unlock(&psinfo->buf_mutex);
+	spin_unlock_irqrestore(&psinfo->buf_lock, flags);
 
 	return 0;
 }
diff --git a/include/linux/pstore.h b/include/linux/pstore.h
index 2455ef2..2d77b82 100644
--- a/include/linux/pstore.h
+++ b/include/linux/pstore.h
@@ -32,7 +32,7 @@ enum pstore_type_id {
 struct pstore_info {
 	struct module	*owner;
 	char		*name;
-	struct mutex	buf_mutex;	/* serialize access to 'buf' */
+	spinlock_t	buf_lock;	/* serialize access to 'buf' */
 	char		*buf;
 	size_t		bufsize;
 	int		(*open)(struct pstore_info *psi);
-- 
1.7.6

Re: [PATCH] pstore: change mutex locking to spin_locks

[Huang Ying]

On 07/21/2011 04:56 AM, Don Zickus wrote:
> pstore was using mutex locking to protect read/write access to the
> backend plug-ins.  This causes problems when pstore is executed in
> an NMI context through panic() -> kmsg_dump().
> 
> This patch changes the mutex to a spin_lock_irqsave then also checks to
> see if we are in an NMI context.  If we are in an NMI and can't get the
> lock, just print a message stating that and blow by the locking.
> 
> All this is probably a hack around the bigger locking problem but it
> solves my current situation of trying to sleep in an NMI context.
> 
> Tested by loading the lkdtm module and executing a HARDLOCKUP which
> will cause the machine to panic inside the nmi handler.
> 
> Signed-off-by: Don Zickus <dzickus@redhat.com>
> ---
>  drivers/acpi/apei/erst.c |    2 +-
>  fs/pstore/platform.c     |   28 ++++++++++++++++++++++------
>  include/linux/pstore.h   |    2 +-
>  3 files changed, 24 insertions(+), 8 deletions(-)
> 
> diff --git a/drivers/acpi/apei/erst.c b/drivers/acpi/apei/erst.c
> index e6cef8e..3d9c2a3 100644
> --- a/drivers/acpi/apei/erst.c
> +++ b/drivers/acpi/apei/erst.c
> @@ -1155,7 +1155,7 @@ static int __init erst_init(void)
>  		goto err_release_erange;
>  
>  	buf = kmalloc(erst_erange.size, GFP_KERNEL);
> -	mutex_init(&erst_info.buf_mutex);
> +	spin_lock_init(&erst_info.buf_lock);
>  	if (buf) {
>  		erst_info.buf = buf + sizeof(struct cper_pstore_record);
>  		erst_info.bufsize = erst_erange.size -
> diff --git a/fs/pstore/platform.c b/fs/pstore/platform.c
> index f2c3ff2..53ba00b 100644
> --- a/fs/pstore/platform.c
> +++ b/fs/pstore/platform.c
> @@ -27,6 +27,7 @@
>  #include <linux/string.h>
>  #include <linux/slab.h>
>  #include <linux/uaccess.h>
> +#include <linux/hardirq.h>
>  
>  #include "internal.h"
>  
> @@ -68,13 +69,21 @@ static void pstore_dump(struct kmsg_dumper *dumper,
>  	char		*dst, *why;
>  	u64		id;
>  	int		hsize, part = 1;
> +	unsigned long	flags = 0;
> +	int 		is_locked = 0;
>  
>  	if (reason < ARRAY_SIZE(reason_str))
>  		why = reason_str[reason];
>  	else
>  		why = "Unknown";
>  
> -	mutex_lock(&psinfo->buf_mutex);
> +	if (in_nmi()) {
> +		is_locked = spin_trylock(&psinfo->buf_lock);
> +		if (!is_locked)
> +			pr_err("pstore dump routine blocked in NMI, may corrupt error record\n");
> +	} else {
> +		spin_lock_irqsave(&psinfo->buf_lock, flags);
> +	}
>  	oopscount++;
>  	while (total < kmsg_bytes) {
>  		dst = psinfo->buf;
> @@ -103,7 +112,12 @@ static void pstore_dump(struct kmsg_dumper *dumper,
>  		l2 -= l2_cpy;
>  		total += l1_cpy + l2_cpy;
>  	}
> -	mutex_unlock(&psinfo->buf_mutex);
> +	if (in_nmi()) {
> +		if (is_locked)
> +			spin_unlock(&psinfo->buf_lock);
> +	} else {
> +		spin_unlock_irqrestore(&psinfo->buf_lock, flags);
> +	}
>  }
>  
>  static struct kmsg_dumper pstore_dumper = {
> @@ -157,11 +171,12 @@ void pstore_get_records(void)
>  	enum pstore_type_id	type;
>  	struct timespec		time;
>  	int			failed = 0, rc;
> +	unsigned long		flags;
>  
>  	if (!psi)
>  		return;
>  
> -	mutex_lock(&psinfo->buf_mutex);
> +	spin_lock_irqsave(&psinfo->buf_lock, flags);
>  	rc = psi->open(psi);
>  	if (rc)
>  		goto out;
> @@ -173,7 +188,7 @@ void pstore_get_records(void)
>  	}
>  	psi->close(psi);
>  out:
> -	mutex_unlock(&psinfo->buf_mutex);
> +	spin_unlock_irqrestore(&psinfo->buf_lock, flags);
>  
>  	if (failed)
>  		printk(KERN_WARNING "pstore: failed to load %d record(s) from '%s'\n",
> @@ -187,6 +202,7 @@ out:
>  int pstore_write(enum pstore_type_id type, char *buf, size_t size)
>  {
>  	u64	id;
> +	unsigned long flags;
>  
>  	if (!psinfo)
>  		return -ENODEV;
> @@ -194,13 +210,13 @@ int pstore_write(enum pstore_type_id type, char *buf, size_t size)
>  	if (size > psinfo->bufsize)
>  		return -EFBIG;
>  
> -	mutex_lock(&psinfo->buf_mutex);
> +	spin_lock_irqsave(&psinfo->buf_lock, flags);
>  	memcpy(psinfo->buf, buf, size);
>  	id = psinfo->write(type, size);
>  	if (pstore_is_mounted())
>  		pstore_mkfile(PSTORE_TYPE_DMESG, psinfo->name, id, psinfo->buf,
>  			      size, CURRENT_TIME, psinfo->erase);
> -	mutex_unlock(&psinfo->buf_mutex);
> +	spin_unlock_irqrestore(&psinfo->buf_lock, flags);

Is it safe to call pstore_mkfile with IRQ disabled?

pstore_mkfile -> d_alloc_name -> d_alloc -> kmem_cache_alloc(, GFP_KERNEL).

Best Regards,
Huang Ying

Re: [PATCH] pstore: change mutex locking to spin_locks

[Don Zickus]

On Thu, Jul 21, 2011 at 08:40:36AM +0800, Huang Ying wrote:
> On 07/21/2011 04:56 AM, Don Zickus wrote:
> > pstore was using mutex locking to protect read/write access to the
> > backend plug-ins.  This causes problems when pstore is executed in
> > an NMI context through panic() -> kmsg_dump().
> > 
> > This patch changes the mutex to a spin_lock_irqsave then also checks to
> > see if we are in an NMI context.  If we are in an NMI and can't get the
> > lock, just print a message stating that and blow by the locking.
> > 
> > All this is probably a hack around the bigger locking problem but it
> > solves my current situation of trying to sleep in an NMI context.
> > 
> > Tested by loading the lkdtm module and executing a HARDLOCKUP which
> > will cause the machine to panic inside the nmi handler.
> > 
> > Signed-off-by: Don Zickus <dzickus@redhat.com>
> > ---
> >  drivers/acpi/apei/erst.c |    2 +-
> >  fs/pstore/platform.c     |   28 ++++++++++++++++++++++------
> >  include/linux/pstore.h   |    2 +-
> >  3 files changed, 24 insertions(+), 8 deletions(-)
> > 
> > diff --git a/drivers/acpi/apei/erst.c b/drivers/acpi/apei/erst.c
> > index e6cef8e..3d9c2a3 100644
> > --- a/drivers/acpi/apei/erst.c
> > +++ b/drivers/acpi/apei/erst.c
> > @@ -1155,7 +1155,7 @@ static int __init erst_init(void)
> >  		goto err_release_erange;
> >  
> >  	buf = kmalloc(erst_erange.size, GFP_KERNEL);
> > -	mutex_init(&erst_info.buf_mutex);
> > +	spin_lock_init(&erst_info.buf_lock);
> >  	if (buf) {
> >  		erst_info.buf = buf + sizeof(struct cper_pstore_record);
> >  		erst_info.bufsize = erst_erange.size -
> > diff --git a/fs/pstore/platform.c b/fs/pstore/platform.c
> > index f2c3ff2..53ba00b 100644
> > --- a/fs/pstore/platform.c
> > +++ b/fs/pstore/platform.c
> > @@ -27,6 +27,7 @@
> >  #include <linux/string.h>
> >  #include <linux/slab.h>
> >  #include <linux/uaccess.h>
> > +#include <linux/hardirq.h>
> >  
> >  #include "internal.h"
> >  
> > @@ -68,13 +69,21 @@ static void pstore_dump(struct kmsg_dumper *dumper,
> >  	char		*dst, *why;
> >  	u64		id;
> >  	int		hsize, part = 1;
> > +	unsigned long	flags = 0;
> > +	int 		is_locked = 0;
> >  
> >  	if (reason < ARRAY_SIZE(reason_str))
> >  		why = reason_str[reason];
> >  	else
> >  		why = "Unknown";
> >  
> > -	mutex_lock(&psinfo->buf_mutex);
> > +	if (in_nmi()) {
> > +		is_locked = spin_trylock(&psinfo->buf_lock);
> > +		if (!is_locked)
> > +			pr_err("pstore dump routine blocked in NMI, may corrupt error record\n");
> > +	} else {
> > +		spin_lock_irqsave(&psinfo->buf_lock, flags);
> > +	}
> >  	oopscount++;
> >  	while (total < kmsg_bytes) {
> >  		dst = psinfo->buf;
> > @@ -103,7 +112,12 @@ static void pstore_dump(struct kmsg_dumper *dumper,
> >  		l2 -= l2_cpy;
> >  		total += l1_cpy + l2_cpy;
> >  	}
> > -	mutex_unlock(&psinfo->buf_mutex);
> > +	if (in_nmi()) {
> > +		if (is_locked)
> > +			spin_unlock(&psinfo->buf_lock);
> > +	} else {
> > +		spin_unlock_irqrestore(&psinfo->buf_lock, flags);
> > +	}
> >  }
> >  
> >  static struct kmsg_dumper pstore_dumper = {
> > @@ -157,11 +171,12 @@ void pstore_get_records(void)
> >  	enum pstore_type_id	type;
> >  	struct timespec		time;
> >  	int			failed = 0, rc;
> > +	unsigned long		flags;
> >  
> >  	if (!psi)
> >  		return;
> >  
> > -	mutex_lock(&psinfo->buf_mutex);
> > +	spin_lock_irqsave(&psinfo->buf_lock, flags);
> >  	rc = psi->open(psi);
> >  	if (rc)
> >  		goto out;
> > @@ -173,7 +188,7 @@ void pstore_get_records(void)
> >  	}
> >  	psi->close(psi);
> >  out:
> > -	mutex_unlock(&psinfo->buf_mutex);
> > +	spin_unlock_irqrestore(&psinfo->buf_lock, flags);
> >  
> >  	if (failed)
> >  		printk(KERN_WARNING "pstore: failed to load %d record(s) from '%s'\n",
> > @@ -187,6 +202,7 @@ out:
> >  int pstore_write(enum pstore_type_id type, char *buf, size_t size)
> >  {
> >  	u64	id;
> > +	unsigned long flags;
> >  
> >  	if (!psinfo)
> >  		return -ENODEV;
> > @@ -194,13 +210,13 @@ int pstore_write(enum pstore_type_id type, char *buf, size_t size)
> >  	if (size > psinfo->bufsize)
> >  		return -EFBIG;
> >  
> > -	mutex_lock(&psinfo->buf_mutex);
> > +	spin_lock_irqsave(&psinfo->buf_lock, flags);
> >  	memcpy(psinfo->buf, buf, size);
> >  	id = psinfo->write(type, size);
> >  	if (pstore_is_mounted())
> >  		pstore_mkfile(PSTORE_TYPE_DMESG, psinfo->name, id, psinfo->buf,
> >  			      size, CURRENT_TIME, psinfo->erase);
> > -	mutex_unlock(&psinfo->buf_mutex);
> > +	spin_unlock_irqrestore(&psinfo->buf_lock, flags);
> 
> Is it safe to call pstore_mkfile with IRQ disabled?
> 
> pstore_mkfile -> d_alloc_name -> d_alloc -> kmem_cache_alloc(, GFP_KERNEL).

Don't know.  But would that mean we would have to put the pstore_mkfile
on a workqueue then or something similar?

Cheers,
Don

RE: [PATCH] pstore: change mutex locking to spin_locks

[Luck, Tony]

> > Is it safe to call pstore_mkfile with IRQ disabled?
> > 
> > pstore_mkfile -> d_alloc_name -> d_alloc -> kmem_cache_alloc(, GFP_KERNEL).
>
> Don't know.  But would that mean we would have to put the pstore_mkfile
> on a workqueue then or something similar?

That might be a good idea anyway.  In the "oops" case we'd like the file
to appear in the pstore filesystem if the system stayed healthy despite
the oops[1]. There isn't any reason why the pstore entry must appear instantly.
Delaying the creation would avoid running into problems related to the
oops.

-Tony

[1] So we can remove it to free pstore backend space - if we didn't die
from the oops, then the oops is going to be in /var/log/messages.

Re: [PATCH] pstore: change mutex locking to spin_locks

[Huang Ying]

On 07/22/2011 01:57 AM, Luck, Tony wrote:
>>> Is it safe to call pstore_mkfile with IRQ disabled?
>>>
>>> pstore_mkfile -> d_alloc_name -> d_alloc -> kmem_cache_alloc(, GFP_KERNEL).
>>
>> Don't know.  But would that mean we would have to put the pstore_mkfile
>> on a workqueue then or something similar?
> 
> That might be a good idea anyway.  In the "oops" case we'd like the file
> to appear in the pstore filesystem if the system stayed healthy despite
> the oops[1]. There isn't any reason why the pstore entry must appear instantly.
> Delaying the creation would avoid running into problems related to the
> oops.

For oops, it may be better to delay writing into something like
workqueue.  But for panic, I think we should write the record to backend
(such as ERST) as soon as possible.  So maybe it is better to write to
backend as soon as possible and delay writing to pstore filesystem.

Best Regards,
Huang Ying

Re: [PATCH] pstore: change mutex locking to spin_locks

[Don Zickus]

On Fri, Jul 22, 2011 at 08:33:22AM +0800, Huang Ying wrote:
> On 07/22/2011 01:57 AM, Luck, Tony wrote:
> >>> Is it safe to call pstore_mkfile with IRQ disabled?
> >>>
> >>> pstore_mkfile -> d_alloc_name -> d_alloc -> kmem_cache_alloc(, GFP_KERNEL).
> >>
> >> Don't know.  But would that mean we would have to put the pstore_mkfile
> >> on a workqueue then or something similar?
> > 
> > That might be a good idea anyway.  In the "oops" case we'd like the file
> > to appear in the pstore filesystem if the system stayed healthy despite
> > the oops[1]. There isn't any reason why the pstore entry must appear instantly.
> > Delaying the creation would avoid running into problems related to the
> > oops.
> 
> For oops, it may be better to delay writing into something like
> workqueue.  But for panic, I think we should write the record to backend
> (such as ERST) as soon as possible.  So maybe it is better to write to
> backend as soon as possible and delay writing to pstore filesystem.

In the panic case do we care if the pstore fs is mounted (which leads us
to run pstore_mkfile)?

Actually it seems like most of the entry points into pstore_dumper would
not require the fs to create a new file.  I think the exception is an
oops.

Cheers,
Don

Re: [PATCH] pstore: change mutex locking to spin_locks

[huang ying]

On Fri, Jul 22, 2011 at 8:13 PM, Don Zickus <dzickus@redhat.com> wrote:
> On Fri, Jul 22, 2011 at 08:33:22AM +0800, Huang Ying wrote:
>> On 07/22/2011 01:57 AM, Luck, Tony wrote:
>> >>> Is it safe to call pstore_mkfile with IRQ disabled?
>> >>>
>> >>> pstore_mkfile -> d_alloc_name -> d_alloc -> kmem_cache_alloc(, GFP_KERNEL).
>> >>
>> >> Don't know.  But would that mean we would have to put the pstore_mkfile
>> >> on a workqueue then or something similar?
>> >
>> > That might be a good idea anyway.  In the "oops" case we'd like the file
>> > to appear in the pstore filesystem if the system stayed healthy despite
>> > the oops[1]. There isn't any reason why the pstore entry must appear instantly.
>> > Delaying the creation would avoid running into problems related to the
>> > oops.
>>
>> For oops, it may be better to delay writing into something like
>> workqueue.  But for panic, I think we should write the record to backend
>> (such as ERST) as soon as possible.  So maybe it is better to write to
>> backend as soon as possible and delay writing to pstore filesystem.
>
> In the panic case do we care if the pstore fs is mounted (which leads us
> to run pstore_mkfile)?
>
> Actually it seems like most of the entry points into pstore_dumper would
> not require the fs to create a new file.  I think the exception is an
> oops.

Yes.  I think so too.

Best Regards,
Huang Ying

RE: [PATCH] pstore: change mutex locking to spin_locks

[Luck, Tony]

> Actually it seems like most of the entry points into pstore_dumper would
> not require the fs to create a new file.  I think the exception is an
> oops.

Yup - oops is the only one where the current kernel continues - all the
others (halt, reboot, kexec, panic) lead to the termination of the
current kernel - and thus no user processes that would be able to
see the shiny new entry in the pstore file system.

-Tony

Re: [PATCH] pstore: change mutex locking to spin_locks

[Tony Luck]

On Fri, Jul 22, 2011 at 3:39 PM, Luck, Tony <tony.luck@intel.com> wrote:
> Yup - oops is the only one where the current kernel continues - all the
> others (halt, reboot, kexec, panic) lead to the termination of the
> current kernel - and thus no user processes that would be able to
> see the shiny new entry in the pstore file system.

Doh - I went to look at what it would take to fix this - and found that
I'd already implemented it:


                if (reason == KMSG_DUMP_OOPS && pstore_is_mounted())
                        pstore_mkfile(PSTORE_TYPE_DMESG, psinfo->name, id,
                                      psinfo->buf, hsize + l1_cpy + l2_cpy,
                                      CURRENT_TIME, psinfo);

-Tony

Re: [PATCH] pstore: change mutex locking to spin_locks

[Don Zickus]

On Fri, Jul 22, 2011 at 04:21:14PM -0700, Tony Luck wrote:
> On Fri, Jul 22, 2011 at 3:39 PM, Luck, Tony <tony.luck@intel.com> wrote:
> > Yup - oops is the only one where the current kernel continues - all the
> > others (halt, reboot, kexec, panic) lead to the termination of the
> > current kernel - and thus no user processes that would be able to
> > see the shiny new entry in the pstore file system.
> 
> Doh - I went to look at what it would take to fix this - and found that
> I'd already implemented it:
> 
> 
>                 if (reason == KMSG_DUMP_OOPS && pstore_is_mounted())
>                         pstore_mkfile(PSTORE_TYPE_DMESG, psinfo->name, id,
>                                       psinfo->buf, hsize + l1_cpy + l2_cpy,
>                                       CURRENT_TIME, psinfo);

Right, but it still has to be created with locks surrounding it.  And the
question is what type of locks should we use.  Mutexes don't work when
called from the NMI case and spinlocks don't seem to work when called from
the OOPs (pstore_mkfile) case.

Cheers,
Don