dle-develop — Dependable Linux Effort mailing list for developers

Re: [Dle-develop] [RFC][PATCH]ACPI, APEI, ERST, back end driver for NVRAM

[Huang Y. <yin...@in...>]

On Sat, 2011-11-19 at 07:04 +0800, Seiji Aguchi wrote:
> Hi,
> 
> >According to ACPI 4.0a spec:
> >
> >"""
> >17.5.2.4.1 Error Log Address Range Resides in NVRAM
> >
> 
> Thank you for giving me the information.
> Let me clarify one thing.
> 
> If the busy bit can be cleared immediately, we don't need to
> check busy bit with CHECK_BUSY_STATUS.
> So, we should simply execute OSPM operations as follows.
> 
>  - Writing
>    1. BEGIN_WRITE
>    2. SET_RECORD_OFFSET
>    3. EXECUTE_OPERATION
>    4. END
> 
>  - Reading
>    1. BEGIN_READ
>    2. SET_RECORD_OFFSET
>    3. SET_RECORD_ID
>    4. EXECUTE_OPERATION
>    (END operation is not needed because OSPM requires no platform 
>     support to read.)
> 
>  - Clearing
>    1. BEGIN_CLEAR
>    2. SET_RECORD_ID
>    3. EXECUTE_OPERATION
>    (END operation is not needed because OSPM requires no platform 
>     support to clear.)
> 
> Is this what you expected?

No.  I have different understanding.

Because error log address range resides in NVRAM, the contents will be
reserved even after reboot.  So we do not need read/clear operations at
all, and should place all records in error log address range.

Best Regards,
Huang Ying

Re: [Dle-develop] [RFC][PATCH]ACPI, APEI, ERST, back end driver for NVRAM

[Seiji A. <sei...@hd...>]

Hi,

>According to ACPI 4.0a spec:
>
>"""
>17.5.2.4.1 Error Log Address Range Resides in NVRAM
>

Thank you for giving me the information.
Let me clarify one thing.

If the busy bit can be cleared immediately, we don't need to
check busy bit with CHECK_BUSY_STATUS.
So, we should simply execute OSPM operations as follows.

 - Writing
   1. BEGIN_WRITE
   2. SET_RECORD_OFFSET
   3. EXECUTE_OPERATION
   4. END

 - Reading
   1. BEGIN_READ
   2. SET_RECORD_OFFSET
   3. SET_RECORD_ID
   4. EXECUTE_OPERATION
   (END operation is not needed because OSPM requires no platform 
    support to read.)

 - Clearing
   1. BEGIN_CLEAR
   2. SET_RECORD_ID
   3. EXECUTE_OPERATION
   (END operation is not needed because OSPM requires no platform 
    support to clear.)

Is this what you expected?

Seiji

Re: [Dle-develop] [RFC][PATCH]ACPI, APEI, ERST, back end driver for NVRAM

[Huang Y. <yin...@in...>]

On Fri, 2011-11-18 at 04:47 +0800, Seiji Aguchi wrote:
> Hi,
> 
> I developed write/read/clear functions of ERST driver for NVRAM. 
> According to ACPI 4.0 specification, we can use the same procedure as storage.
> 
> This patch is tested on DELL PowerEdge T310.

This machine has error log address range in NVRAM?

According to ACPI 4.0a spec:

"""
17.5.2.4.1 Error Log Address Range Resides in NVRAM

If the Error Log Address Range resides in NVRAM, then when OSPM writes a
record into the logging
range, the record is automatically persistent and the busy bit can be
cleared immediately. On a subsequent
boot, OSPM can read any persisted error records directly from the
persistent store range. The size of the
persistent store, in this case, is expected to be enough for several
error records.
"""

So it should not work with the same procedure.

Best Regards,
Huang Ying

[Dle-develop] [RFC][PATCH]ACPI, APEI, ERST, back end driver for NVRAM

[Seiji A. <sei...@hd...>]

Hi,

I developed write/read/clear functions of ERST driver for NVRAM. 
According to ACPI 4.0 specification, we can use the same procedure as storage.

This patch is tested on DELL PowerEdge T310.

Any comments are welcome.

 Signed-off-by: Seiji Aguchi <sei...@hd...>

---
 drivers/acpi/apei/erst.c |  145 +++++++++++++++++++++++++++++++++++++---------
 1 files changed, 117 insertions(+), 28 deletions(-)

diff --git a/drivers/acpi/apei/erst.c b/drivers/acpi/apei/erst.c
index 1274080..4806283 100644
--- a/drivers/acpi/apei/erst.c
+++ b/drivers/acpi/apei/erst.c
@@ -755,30 +755,125 @@ static int __erst_clear_from_storage(u64 record_id)
 	return erst_errno(val);
 }
 
-/* NVRAM ERST Error Log Address Range is not supported yet */
-static void pr_unimpl_nvram(void)
+static int __erst_write_to_nvram(u64 offset)
 {
-	if (printk_ratelimit())
-		pr_warning(ERST_PFX
-		"NVRAM ERST Log Address Range is not implemented yet\n");
-}
+	struct apei_exec_context ctx;
+	u64 timeout = FIRMWARE_TIMEOUT;
+	u64 val;
+	int rc;
 
-static int __erst_write_to_nvram(const struct cper_record_header *record)
-{
-	/* do not print message, because printk is not safe for NMI */
-	return -ENOSYS;
+	erst_exec_ctx_init(&ctx);
+	rc = apei_exec_run_optional(&ctx, ACPI_ERST_BEGIN_WRITE);
+	if (rc)
+		return rc;
+	apei_exec_ctx_set_input(&ctx, offset);
+	rc = apei_exec_run(&ctx, ACPI_ERST_SET_RECORD_OFFSET);
+	if (rc)
+		return rc;
+	rc = apei_exec_run(&ctx, ACPI_ERST_EXECUTE_OPERATION);
+	if (rc)
+		return rc;
+	for (;;) {
+		rc = apei_exec_run(&ctx, ACPI_ERST_CHECK_BUSY_STATUS);
+		if (rc)
+			return rc;
+		val = apei_exec_ctx_get_output(&ctx);
+		if (!val)
+			break;
+		if (erst_timedout(&timeout, SPIN_UNIT))
+			return -EIO;
+	}
+	rc = apei_exec_run(&ctx, ACPI_ERST_GET_COMMAND_STATUS);
+	if (rc)
+		return rc;
+	val = apei_exec_ctx_get_output(&ctx);
+	rc = apei_exec_run_optional(&ctx, ACPI_ERST_END);
+	if (rc)
+		return rc;
+
+	return erst_errno(val);
 }
 
-static int __erst_read_to_erange_from_nvram(u64 record_id, u64 *offset)
+static int __erst_read_to_erange_from_nvram(u64 record_id, u64 offset)
 {
-	pr_unimpl_nvram();
-	return -ENOSYS;
+	struct apei_exec_context ctx;
+	u64 timeout = FIRMWARE_TIMEOUT;
+	u64 val;
+	int rc;
+
+	erst_exec_ctx_init(&ctx);
+	rc = apei_exec_run_optional(&ctx, ACPI_ERST_BEGIN_READ);
+	if (rc)
+		return rc;
+	apei_exec_ctx_set_input(&ctx, offset);
+	rc = apei_exec_run(&ctx, ACPI_ERST_SET_RECORD_OFFSET);
+	if (rc)
+		return rc;
+	apei_exec_ctx_set_input(&ctx, record_id);
+	rc = apei_exec_run(&ctx, ACPI_ERST_SET_RECORD_ID);
+	if (rc)
+		return rc;
+	rc = apei_exec_run(&ctx, ACPI_ERST_EXECUTE_OPERATION);
+	if (rc)
+		return rc;
+	for (;;) {
+		rc = apei_exec_run(&ctx, ACPI_ERST_CHECK_BUSY_STATUS);
+		if (rc)
+			return rc;
+		val = apei_exec_ctx_get_output(&ctx);
+		if (!val)
+			break;
+		if (erst_timedout(&timeout, SPIN_UNIT))
+			return -EIO;
+	}
+	rc = apei_exec_run(&ctx, ACPI_ERST_GET_COMMAND_STATUS);
+	if (rc)
+		return rc;
+	val = apei_exec_ctx_get_output(&ctx);
+	rc = apei_exec_run_optional(&ctx, ACPI_ERST_END);
+	if (rc)
+		return rc;
+
+	return erst_errno(val);
 }
 
 static int __erst_clear_from_nvram(u64 record_id)
 {
-	pr_unimpl_nvram();
-	return -ENOSYS;
+	struct apei_exec_context ctx;
+	u64 timeout = FIRMWARE_TIMEOUT;
+	u64 val;
+	int rc;
+
+	erst_exec_ctx_init(&ctx);
+	rc = apei_exec_run_optional(&ctx, ACPI_ERST_BEGIN_CLEAR);
+	if (rc)
+		return rc;
+	apei_exec_ctx_set_input(&ctx, record_id);
+	rc = apei_exec_run(&ctx, ACPI_ERST_SET_RECORD_ID);
+	if (rc)
+		return rc;
+	rc = apei_exec_run(&ctx, ACPI_ERST_EXECUTE_OPERATION);
+	if (rc)
+		return rc;
+	for (;;) {
+		rc = apei_exec_run(&ctx, ACPI_ERST_CHECK_BUSY_STATUS);
+		if (rc)
+			return rc;
+		val = apei_exec_ctx_get_output(&ctx);
+		if (!val)
+			break;
+		if (erst_timedout(&timeout, SPIN_UNIT))
+			return -EIO;
+	}
+	rc = apei_exec_run(&ctx, ACPI_ERST_GET_COMMAND_STATUS);
+	if (rc)
+		return rc;
+	val = apei_exec_ctx_get_output(&ctx);
+	rc = apei_exec_run_optional(&ctx, ACPI_ERST_END);
+	if (rc)
+		return rc;
+
+	return erst_errno(val);
 }
 
 int erst_write(const struct cper_record_header *record)
@@ -793,14 +888,6 @@ int erst_write(const struct cper_record_header *record)
 	if (memcmp(record->signature, CPER_SIG_RECORD, CPER_SIG_SIZE))
 		return -EINVAL;
 
-	if (erst_erange.attr & ERST_RANGE_NVRAM) {
-		if (!raw_spin_trylock_irqsave(&erst_lock, flags))
-			return -EBUSY;
-		rc = __erst_write_to_nvram(record);
-		raw_spin_unlock_irqrestore(&erst_lock, flags);
-		return rc;
-	}
-
 	if (record->record_length > erst_erange.size)
 		return -EINVAL;
 
@@ -811,7 +898,10 @@ int erst_write(const struct cper_record_header *record)
 	/* signature for serialization system */
 	memcpy(&rcd_erange->persistence_information, "ER", 2);
 
-	rc = __erst_write_to_storage(0);
+	if (erst_erange.attr & ERST_RANGE_NVRAM)
+		rc = __erst_write_to_nvram(0);
+	else
+		rc = __erst_write_to_storage(0);
 	raw_spin_unlock_irqrestore(&erst_lock, flags);
 
 	return rc;
@@ -823,10 +913,9 @@ static int __erst_read_to_erange(u64 record_id, u64 *offset)
 	int rc;
 
 	if (erst_erange.attr & ERST_RANGE_NVRAM)
-		return __erst_read_to_erange_from_nvram(
-			record_id, offset);
-
-	rc = __erst_read_from_storage(record_id, 0);
+		rc = __erst_read_to_erange_from_nvram(record_id, 0);
+	else
+		rc = __erst_read_from_storage(record_id, 0);
 	if (rc)
 		return rc;
 	*offset = 0;
-- 
1.7.1

Re: [Dle-develop] [RFC][PATCH v2 -next 2/2] Adding lock operations to kmsg_dump()/pstore_dump()

[Don Z. <dz...@re...>]

On Thu, Nov 10, 2011 at 01:50:25PM +0100, Peter Zijlstra wrote:
> On Fri, 2011-10-21 at 17:21 -0400, Seiji Aguchi wrote:
> > +++ b/fs/pstore/platform.c
> > @@ -97,6 +97,17 @@ static void pstore_dump(struct kmsg_dumper *dumper,
> >         else
> >                 why = "Unknown";
> >  
> > +       /*
> > +        * pstore_dump() is called after smp_send_stop() in panic path.
> > +        * So, spin_lock should be bust for avoiding deadlock.
> > +        */
> > +       if (reason == KMSG_DUMP_PANIC)
> > +               spin_lock_init(&psinfo->buf_lock);
> > +
> > +       /*
> > +        * While a cpu is in NMI handler, other cpus may be running.
> > +        * So, trylock should be called so that lockdep checking works.
> > +        */
> 
> Don't be silly, lockdep doesn't cover NMI, in fact you shouldn't use
> locks from NMI context ever.

Heh.  I would normally agree, but in this case we have a piece of hardware
that can be accessed from normal, irq and NMI context.  I still scratch my
head for the best way to handle this.  This approach was sorta of a
bandaid effort to prevent a deadlock in the NMI panic case.

> 
> >         if (in_nmi()) {
> >                 is_locked = spin_trylock(&psinfo->buf_lock);
> >                 if (!is_locked)
> > diff --git a/kernel/printk.c b/kernel/printk.c
> > index 1455a0d..f51f547 100644
> > --- a/kernel/printk.c
> > +++ b/kernel/printk.c
> > @@ -1730,15 +1730,37 @@ void kmsg_dump(enum kmsg_dump_reason reason)
> >         struct kmsg_dumper *dumper;
> >         const char *s1, *s2;
> >         unsigned long l1, l2;
> > -       unsigned long flags;
> > +       unsigned long flags = 0;
> > +       int is_locked = 0;
> >  
> >         /* Theoretically, the log could move on after we do this, but
> >            there's not a lot we can do about that. The new messages
> >            will overwrite the start of what we dump. */
> > -       raw_spin_lock_irqsave(&logbuf_lock, flags);
> > +
> > +       /*
> > +        * kmsg_dump() is called after smp_send_stop() in panic path.
> > +        * So, spin_lock should be bust for avoiding deadlock.
> > +        */
> > +       if (reason == KMSG_DUMP_PANIC)
> > +               raw_spin_lock_init(&logbuf_lock); 
> 
> In both cases where you bust the spinlock at least yell loudly and
> disable lock debugging.
> 
> And I guess this is where Don wants to use NMIs for smp_send_stop() so
> what you get around the fact that this lock you're busting disabled
> IRQs?

:-)  I thought it would be safer to bust spinlocks if we could have a
better gaurantee the other cpus were not accessing the hardware at the
same time.

> 
> All in all this patch is way ugly and doesn't make me feel all warm and
> fuzzy.

I understand.

Cheers,
Don

Re: [Dle-develop] [RFC][PATCH v2 -next 2/2] Adding lock operations to kmsg_dump()/pstore_dump()

[Peter Z. <a.p...@ch...>]

On Fri, 2011-10-21 at 17:21 -0400, Seiji Aguchi wrote:
> +++ b/fs/pstore/platform.c
> @@ -97,6 +97,17 @@ static void pstore_dump(struct kmsg_dumper *dumper,
>         else
>                 why = "Unknown";
>  
> +       /*
> +        * pstore_dump() is called after smp_send_stop() in panic path.
> +        * So, spin_lock should be bust for avoiding deadlock.
> +        */
> +       if (reason == KMSG_DUMP_PANIC)
> +               spin_lock_init(&psinfo->buf_lock);
> +
> +       /*
> +        * While a cpu is in NMI handler, other cpus may be running.
> +        * So, trylock should be called so that lockdep checking works.
> +        */

Don't be silly, lockdep doesn't cover NMI, in fact you shouldn't use
locks from NMI context ever.

>         if (in_nmi()) {
>                 is_locked = spin_trylock(&psinfo->buf_lock);
>                 if (!is_locked)
> diff --git a/kernel/printk.c b/kernel/printk.c
> index 1455a0d..f51f547 100644
> --- a/kernel/printk.c
> +++ b/kernel/printk.c
> @@ -1730,15 +1730,37 @@ void kmsg_dump(enum kmsg_dump_reason reason)
>         struct kmsg_dumper *dumper;
>         const char *s1, *s2;
>         unsigned long l1, l2;
> -       unsigned long flags;
> +       unsigned long flags = 0;
> +       int is_locked = 0;
>  
>         /* Theoretically, the log could move on after we do this, but
>            there's not a lot we can do about that. The new messages
>            will overwrite the start of what we dump. */
> -       raw_spin_lock_irqsave(&logbuf_lock, flags);
> +
> +       /*
> +        * kmsg_dump() is called after smp_send_stop() in panic path.
> +        * So, spin_lock should be bust for avoiding deadlock.
> +        */
> +       if (reason == KMSG_DUMP_PANIC)
> +               raw_spin_lock_init(&logbuf_lock); 

In both cases where you bust the spinlock at least yell loudly and
disable lock debugging.

And I guess this is where Don wants to use NMIs for smp_send_stop() so
what you get around the fact that this lock you're busting disabled
IRQs?

All in all this patch is way ugly and doesn't make me feel all warm and
fuzzy.

Re: [Dle-develop] [RFC][PATCH v2 -next 2/2] Adding lock operations to kmsg_dump()/pstore_dump()

[Don Z. <dz...@re...>]

On Fri, Oct 28, 2011 at 12:02:15PM -0700, Luck, Tony wrote:
> > It ain't pretty but it moves things towards a more reliable message dump.
> > The odds of us needing to bust the spinlocks are really small.  Most of
> > the time no one reads the pstore filesystem.
> 
> Does it really change the odds much?  As you say, the common case is that
> pstore front-end doesn't have the lock held - so that case is unchanged.
> We can get the lock anyway, we don't need to bust it.

Agreed.

> 
> Looking at the uncommon case where the lock is held - that means that
> pstore was in the middle of some back-end operation. Busting the lock
> means that the back-end will be surprised by being called again when the
> first operation had not yet completed. In the case of a state machine
> driven back end like ERST, I don't think this has a high probability of
> working out well.

Remember ERST has two modes, state machine and NVRAM.  The state machine
will have issues, but the NVRAM part (which isn't implemented yet) might
not.  Not sure about EFI. But shouldn't the backend determine that, not pstore?

> 
> So you might be moving the needle from 99.999% chance of saving to pstore
> with 0.001% chance of hanging on the spin lock. to 99.9991% chance of
> saving, and 0.0009% chance of something highly weird happening in the
> back-end driver because you busted the lock and called it anyway.

Sure.  But at the same time, APEI is one of those 'value add' by OEMs.  If
you are paying $20K for this feature, wouldn't you expect this feature to
work 100% of the time?  At least with kdump/netdump, you can say, hey it
was free so you get what you pay for.

I guess it would help if we had more machines with working firmware to
test this.

> 
> > I would love to figure out a prettier solution for this locking mess, but
> > I can't think of anything.  We have customers who want to utilize this
> > technology, so I am trying to make sure it is stable and robust for now.
> > A little selfish I suppose.  But we are open to ideas?
> 
> If a prettier solution is needed - it will have to involve the back-end.
> Perhaps a whole separate write/panic path (with separate buffer). Then
> a sufficiently smart back end could do the right thing. I have little
> confidence that ERST could be made smart in this way, because almost all
> of the heavy lifting is done by the BIOS - so Linux has no way to influence
> the flow of execution.

Sadly I agree.

Perhaps I have been hanging around mjg too much, but I little confidence
in anything ACPI related being smart.

I don't have that much motivation to push this patch very hard.  I just
saw some a theoretical issue and thought I could help Seiji solve it.  I
am more interested in getting the first patch of this series in than this one.

If you find this patch adds more complexity for very little gain, so be
it.  We tried. :-)

Cheers,
Don

Re: [Dle-develop] [RFC][PATCH v2 -next 2/2] Adding lock operations to kmsg_dump()/pstore_dump()

[Luck, T. <ton...@in...>]

> It ain't pretty but it moves things towards a more reliable message dump.
> The odds of us needing to bust the spinlocks are really small.  Most of
> the time no one reads the pstore filesystem.

Does it really change the odds much?  As you say, the common case is that
pstore front-end doesn't have the lock held - so that case is unchanged.
We can get the lock anyway, we don't need to bust it.

Looking at the uncommon case where the lock is held - that means that
pstore was in the middle of some back-end operation. Busting the lock
means that the back-end will be surprised by being called again when the
first operation had not yet completed. In the case of a state machine
driven back end like ERST, I don't think this has a high probability of
working out well.

So you might be moving the needle from 99.999% chance of saving to pstore
with 0.001% chance of hanging on the spin lock. to 99.9991% chance of
saving, and 0.0009% chance of something highly weird happening in the
back-end driver because you busted the lock and called it anyway.

> I would love to figure out a prettier solution for this locking mess, but
> I can't think of anything.  We have customers who want to utilize this
> technology, so I am trying to make sure it is stable and robust for now.
> A little selfish I suppose.  But we are open to ideas?

If a prettier solution is needed - it will have to involve the back-end.
Perhaps a whole separate write/panic path (with separate buffer). Then
a sufficiently smart back end could do the right thing. I have little
confidence that ERST could be made smart in this way, because almost all
of the heavy lifting is done by the BIOS - so Linux has no way to influence
the flow of execution.

-Tony

Re: [Dle-develop] [RFC][PATCH v2 -next 2/2] Adding lock operations to kmsg_dump()/pstore_dump()

[Don Z. <dz...@re...>]

On Fri, Oct 21, 2011 at 05:21:35PM -0400, Seiji Aguchi wrote:
> pstore_dump()/kmsg_dump() may be called everywhere in kernel.
> So we have to care about following cases.
> 
>   - Panic path
>     In this case, Logging message process is serialized via smp_send_stop().
>     So, we can bust spin_locks.
> 
>     Currently, kmsg_dump() may be called twice (KMSG_DUMP_PANIC and KMSG_DUMP_EMERGY)
>     So, for avoiding deadlock, I suggest to bust locks rather than skipping them.
> 
>   - NMI context 
>      While a cpu is in NMI handler, other cpus may be running.
>      So, trylock should be called so that lockdep cheking works.
>  
>   - Process context
>     In this case, we can simply take locks.

It ain't pretty but it moves things towards a more reliable message dump.
The odds of us needing to bust the spinlocks are really small.  Most of
the time no one reads the pstore filesystem.

I would love to figure out a prettier solution for this locking mess, but
I can't think of anything.  We have customers who want to utilize this
technology, so I am trying to make sure it is stable and robust for now.
A little selfish I suppose.  But we are open to ideas?

Acked-by: Don Zickus <dz...@re...>

Re: [Dle-develop] [RFC][PATCH v2 -next 1/2] Move kmsg_dump(KMSG_DUMP_PANIC) below smp_send_stop()

[Don Z. <dz...@re...>]

On Fri, Oct 21, 2011 at 05:20:07PM -0400, Seiji Aguchi wrote:
> This patch is just moving kmsg_dump(KMSG_DUMP_PANIC) below smp_send_stop
> for serializing logging process via smp_send_stop.

I feel it is good to always serialize the logging when we are panic'ing.
So this patch is a step in the right direction.

Acked-by: Don Zickus <dz...@re...>

> 
>  Signed-off-by: Seiji Aguchi <sei...@hd...>
> 
> ---
>  kernel/panic.c |    4 ++--
>  1 files changed, 2 insertions(+), 2 deletions(-)
> 
> diff --git a/kernel/panic.c b/kernel/panic.c
> index d7bb697..41bf6ad 100644
> --- a/kernel/panic.c
> +++ b/kernel/panic.c
> @@ -88,8 +88,6 @@ NORET_TYPE void panic(const char * fmt, ...)
>  	 */
>  	crash_kexec(NULL);
>  
> -	kmsg_dump(KMSG_DUMP_PANIC);
> -
>  	/*
>  	 * Note smp_send_stop is the usual smp shutdown function, which
>  	 * unfortunately means it may not be hardened to work in a panic
> @@ -97,6 +95,8 @@ NORET_TYPE void panic(const char * fmt, ...)
>  	 */
>  	smp_send_stop();
>  
> +	kmsg_dump(KMSG_DUMP_PANIC);
> +
>  	atomic_notifier_call_chain(&panic_notifier_list, 0, buf);
>  
>  	bust_spinlocks(0);
> -- 1.7.1

[Dle-develop] [RFC][PATCH v2 -next 2/2] Adding lock operations to kmsg_dump()/pstore_dump()

[Seiji A. <sei...@hd...>]

pstore_dump()/kmsg_dump() may be called everywhere in kernel.
So we have to care about following cases.

  - Panic path
    In this case, Logging message process is serialized via smp_send_stop().
    So, we can bust spin_locks.

    Currently, kmsg_dump() may be called twice (KMSG_DUMP_PANIC and KMSG_DUMP_EMERGY)
    So, for avoiding deadlock, I suggest to bust locks rather than skipping them.

  - NMI context 
     While a cpu is in NMI handler, other cpus may be running.
     So, trylock should be called so that lockdep cheking works.
 
  - Process context
    In this case, we can simply take locks.

Patch Descriptions:
  Adding a lock operation below in pstore_dump()
  - busting psinfo->buf_lock of pstore_dump() in panic path for avoiding deadlock.

  Adding lock operations below in kmsg_dump()
  - busting logbuf_lock of kmsg_dump() in panic path for avoiding deadlock.
  - Adding trylock for taking logbuf_lock of kmsg_dump() in NMI context. 
  

 Signed-off-by: Seiji Aguchi <sei...@hd...>

---
 fs/pstore/platform.c |   11 +++++++++++
 kernel/printk.c      |   28 +++++++++++++++++++++++++---
 2 files changed, 36 insertions(+), 3 deletions(-)

diff --git a/fs/pstore/platform.c b/fs/pstore/platform.c
index 2bd620f..91ef164 100644
--- a/fs/pstore/platform.c
+++ b/fs/pstore/platform.c
@@ -97,6 +97,17 @@ static void pstore_dump(struct kmsg_dumper *dumper,
 	else
 		why = "Unknown";
 
+	/*
+	 * pstore_dump() is called after smp_send_stop() in panic path.
+	 * So, spin_lock should be bust for avoiding deadlock.
+	 */
+	if (reason == KMSG_DUMP_PANIC)
+		spin_lock_init(&psinfo->buf_lock);
+
+	/*
+	 * While a cpu is in NMI handler, other cpus may be running.
+	 * So, trylock should be called so that lockdep checking works.
+	 */
 	if (in_nmi()) {
 		is_locked = spin_trylock(&psinfo->buf_lock);
 		if (!is_locked)
diff --git a/kernel/printk.c b/kernel/printk.c
index 1455a0d..f51f547 100644
--- a/kernel/printk.c
+++ b/kernel/printk.c
@@ -1730,15 +1730,37 @@ void kmsg_dump(enum kmsg_dump_reason reason)
 	struct kmsg_dumper *dumper;
 	const char *s1, *s2;
 	unsigned long l1, l2;
-	unsigned long flags;
+	unsigned long flags = 0;
+	int is_locked = 0;
 
 	/* Theoretically, the log could move on after we do this, but
 	   there's not a lot we can do about that. The new messages
 	   will overwrite the start of what we dump. */
-	raw_spin_lock_irqsave(&logbuf_lock, flags);
+
+	/*
+	 * kmsg_dump() is called after smp_send_stop() in panic path.
+	 * So, spin_lock should be bust for avoiding deadlock.
+	 */
+	if (reason == KMSG_DUMP_PANIC)
+		raw_spin_lock_init(&logbuf_lock);
+	/*
+	 * While a cpu is in NMI handler, other cpus may be running.
+	 * So, trylock should be called so that lockdep checking works.
+	 */
+	if (in_nmi())
+		is_locked = raw_spin_trylock(&logbuf_lock);
+	else
+		raw_spin_lock_irqsave(&logbuf_lock, flags);
+
 	end = log_end & LOG_BUF_MASK;
 	chars = logged_chars;
-	raw_spin_unlock_irqrestore(&logbuf_lock, flags);
+
+	if (in_nmi()) {
+		if (is_locked)
+			raw_spin_unlock(&logbuf_lock);
+	} else
+		raw_spin_unlock_irqrestore(&logbuf_lock, flags);
+
 
 	if (chars > end) {
 		s1 = log_buf + log_buf_len - chars + end;
-- 1.7.1

[Dle-develop] [RFC][PATCH v2 -next 1/2] Move kmsg_dump(KMSG_DUMP_PANIC) below smp_send_stop()

[Seiji A. <sei...@hd...>]

This patch is just moving kmsg_dump(KMSG_DUMP_PANIC) below smp_send_stop
for serializing logging process via smp_send_stop.

 Signed-off-by: Seiji Aguchi <sei...@hd...>

---
 kernel/panic.c |    4 ++--
 1 files changed, 2 insertions(+), 2 deletions(-)

diff --git a/kernel/panic.c b/kernel/panic.c
index d7bb697..41bf6ad 100644
--- a/kernel/panic.c
+++ b/kernel/panic.c
@@ -88,8 +88,6 @@ NORET_TYPE void panic(const char * fmt, ...)
 	 */
 	crash_kexec(NULL);
 
-	kmsg_dump(KMSG_DUMP_PANIC);
-
 	/*
 	 * Note smp_send_stop is the usual smp shutdown function, which
 	 * unfortunately means it may not be hardened to work in a panic
@@ -97,6 +95,8 @@ NORET_TYPE void panic(const char * fmt, ...)
 	 */
 	smp_send_stop();
 
+	kmsg_dump(KMSG_DUMP_PANIC);
+
 	atomic_notifier_call_chain(&panic_notifier_list, 0, buf);
 
 	bust_spinlocks(0);
-- 1.7.1

[Dle-develop] [RFC][PATCH v2 -next 0/2] make pstore/kmsg_dump run after stopping other cpus in panic path

[Seiji A. <sei...@hd...>]

Hi,

 As Don mentioned in following thread, it would be nice for pstore/kmsg_dump to serialize 
 panic path and have one cpu running  because they can log messages reliably. 
 
 https://lkml.org/lkml/2011/10/13/427
 
 For realizing this idea, we have to move kmsg_dump below smp_send_stop() and bust some locks of 
 kmsg_dump/pstore in panic path. Also, we have to care about NMI interrupt.

Changelog:
 v2
  - Adding trylocks to kmsg_dump()/pstore_dump() so that they can work in NMI context.  
  - Dividing a patch into two. 
     First one is just moving kmsg_dump(KMSG_DUMP_PANIC) below smp_send_stop().
     Second one is changing lock operations in kmsg_dump()/pstore_dump().
 v1
  - moving kmsg_dump(KMSG_DUMP_PANIC) below smp_send_stop.
  - busting logbuf_lock of kmsg_dump() in panic path for avoiding deadlock.
  - busting psinfo->buf_lock of pstore_dump() in panic path for avoiding deadlock.

Patch Descriptions:
[RFC][PATCH -next v2 1/2] Moving kmsg_dump(KMSG_DUMP_PANIC) below smp_send_stop()
  - moving kmsg_dump(KMSG_DUMP_PANIC) below smp_send_stop for serializing logging 
    process via smp_send_stop.

[RFC][PATCH v2 -next 2/2] Adding lock operations to kmsg_dump()/pstore_dump()
  Adding a lock operation below in pstore_dump()
  - busting psinfo->buf_lock of pstore_dump() in panic path for avoiding deadlock.

  Adding lock operations below in kmsg_dump()
  - busting logbuf_lock of kmsg_dump() in panic path for avoiding deadlock.
  - Adding trylock for taking logbuf_lock of kmsg_dump() in NMI context. 

Seiji

Re: [Dle-develop] [RFC][PATCH -next] make pstore/kmsg_dump run after stopping other cpus in panic path

[Seiji A. <sei...@hd...>]

Hi,

>I am confused.  Did you mean 'panic' kernel parameter is _not_ set?
>

I meant that  if panic parameter _is_ set (like panic=1), 
emergency_restart() will be called in panic path.
And then, kmsg_dump(KMSG_DUMP_EMERG) will be called.

        <snip>
	60 NORET_TYPE void panic(const char * fmt, ...)  
	61 {
	.
	.
	123         if (panic_timeout != 0) { 
	124                 /* 
	125                  * This will not be a clean reboot, with everything 
	126                  * shutting down.  But if there is a chance of 
	127                  * rebooting the system it will be rebooted. 
	128                  */ 
	129                 emergency_restart(); 
	130         }
	<snip>

>Actually, BUG_ON is probably overkill, perhaps a WARN_ON would be more
>appropriate.

I don't think both BUG_ON and WARN_ON are appropriate.
kmsg_dump(KMSG_DUMP_EMERG) should be called successfully in panic path.

>I wonder if it would be smarter to split your patch in half.  The part
>where you move kmsg_dump to below stop_cpus is probably non-controversial.
>That might make it sooner than the more controversial bust_spinlock
>pieces.

Thank you for your suggestion. I will split my patch.

Seiji

>On Thu, Oct 20, 2011 at 11:13:26AM -0400, Seiji Aguchi wrote:
>> Don,
>>
>> >That is part of the wider problem with kmsg_dump that Vivek talks about
>> >with me, is that it is just a giant hook in the panic path with limited
>> >auditing.  So we need to explicit set our expectations with BUG_ONs/WARNs
>> >otherwise we might get bit later by them.
>>
>> I found an issue while developing a patch v2.
>>
>> We can't call BUG_ON(in_nmi() && reason != KMSG_DUMP_PANIC)
>> because kmsg_dump(KMSG_DUMP_EMERG) is called in NMI context if "panic" kernel parameter is set.
>
>I am confused.  Did you mean 'panic' kernel parameter is _not_ set?
>
>Actually, BUG_ON is probably overkill, perhaps a WARN_ON would be more
>appropriate.
>
>>
>> I will keep doing research bust_spinlock() or vprintk() so that lockdep checking works and we can avoid any deadlocks.
>
>I wonder if it would be smarter to split your patch in half.  The part
>where you move kmsg_dump to below stop_cpus is probably non-controversial.
>That might make it sooner than the more controversial bust_spinlock
>pieces.
>
>Cheers,
>Don

Re: [Dle-develop] [RFC][PATCH -next] make pstore/kmsg_dump run after stopping other cpus in panic path

[Don Z. <dz...@re...>]

On Thu, Oct 20, 2011 at 11:13:26AM -0400, Seiji Aguchi wrote:
> Don,
> 
> >That is part of the wider problem with kmsg_dump that Vivek talks about
> >with me, is that it is just a giant hook in the panic path with limited
> >auditing.  So we need to explicit set our expectations with BUG_ONs/WARNs
> >otherwise we might get bit later by them.
> 
> I found an issue while developing a patch v2.
> 
> We can't call BUG_ON(in_nmi() && reason != KMSG_DUMP_PANIC)
> because kmsg_dump(KMSG_DUMP_EMERG) is called in NMI context if "panic" kernel parameter is set.

I am confused.  Did you mean 'panic' kernel parameter is _not_ set?

Actually, BUG_ON is probably overkill, perhaps a WARN_ON would be more
appropriate.

> 
> I will keep doing research bust_spinlock() or vprintk() so that lockdep checking works and we can avoid any deadlocks.

I wonder if it would be smarter to split your patch in half.  The part
where you move kmsg_dump to below stop_cpus is probably non-controversial.
That might make it sooner than the more controversial bust_spinlock
pieces.

Cheers,
Don

Re: [Dle-develop] [RFC][PATCH -next] make pstore/kmsg_dump run after stopping other cpus in panic path

[Seiji A. <sei...@hd...>]

Don,

>That is part of the wider problem with kmsg_dump that Vivek talks about
>with me, is that it is just a giant hook in the panic path with limited
>auditing.  So we need to explicit set our expectations with BUG_ONs/WARNs
>otherwise we might get bit later by them.

I found an issue while developing a patch v2.

We can't call BUG_ON(in_nmi() && reason != KMSG_DUMP_PANIC)
because kmsg_dump(KMSG_DUMP_EMERG) is called in NMI context if "panic" kernel parameter is set.

I will keep doing research bust_spinlock() or vprintk() so that lockdep checking works and we can avoid any deadlocks.

Seiji

Re: [Dle-develop] [RFC][PATCH -next] make pstore/kmsg_dump run after stopping other cpus in panic path

[Don Z. <dz...@re...>]

On Tue, Oct 18, 2011 at 10:52:22AM -0400, Seiji Aguchi wrote:
> Hi,
> 
> >> afacit this assumes that (reason == KMSG_DUMP_PANIC) if in_nmi().  Is
> >> that always the case, and will it always be the case in the future?
> >
> 
> Currently, when kernel is in nmi context and kmsg_dump() are called, its reason is always "KMSG_DUMP_PANIC".
> 
> >
> >Perhaps a 'BUG_ON(in_nmi() && reason != KMSG_DUMP_PANIC)'?
> 
> I don't think BUG_ON() is needed.
> 
> If someone would like to log messages in the case of "in_nmi() && reason != KMSG_DUMP_PANIC",
> he/she will add a new trigger as follows.

The point I was trying to make with the BUG_ON is to catch future uses of
NMI and kmsg_dump that were implemented without understanding the
restriction we place (you have to be in a panic path for NMI to use
pstore/kmsg_dump).

That is part of the wider problem with kmsg_dump that Vivek talks about
with me, is that it is just a giant hook in the panic path with limited
auditing.  So we need to explicit set our expectations with BUG_ONs/WARNs
otherwise we might get bit later by them.

Cheers,
Don

Re: [Dle-develop] [RFC][PATCH -next] make pstore/kmsg_dump run after stopping other cpus in panic path

[Seiji A. <sei...@hd...>]

Hi,

>> afacit this assumes that (reason == KMSG_DUMP_PANIC) if in_nmi().  Is
>> that always the case, and will it always be the case in the future?
>

Currently, when kernel is in nmi context and kmsg_dump() are called, its reason is always "KMSG_DUMP_PANIC".

>
>Perhaps a 'BUG_ON(in_nmi() && reason != KMSG_DUMP_PANIC)'?

I don't think BUG_ON() is needed.

If someone would like to log messages in the case of "in_nmi() && reason != KMSG_DUMP_PANIC",
he/she will add a new trigger as follows.

We can discuss implementation of kmsg_dump() at that time.
But I can't see any use case now.

	371 static notrace __kprobes void 
	372 unknown_nmi_error(unsigned char reason, struct pt_regs *regs) 
	373 {
	374         if (notify_die(DIE_NMIUNKNOWN, "nmi", regs, reason, 2, SIGINT) == 
	375                         NOTIFY_STOP) 
	376                 return; 
	377 #ifdef CONFIG_MCA 
	378         /* 
	379          * Might actually be able to figure out what the guilty party 
	380          * is: 
	381          */ 
	382         if (MCA_bus) { 
	383                 mca_handle_nmi(); 
	384                 return; 
	385         } 
	386 #endif 
	387         pr_emerg("Uhhuh. NMI received for unknown reason %02x on CPU %d.\n", 
	388                  reason, smp_processor_id()); 
	389  
	390         pr_emerg("Do you have a strange power saving mode enabled?\n"); 
	391         if (unknown_nmi_panic || panic_on_unrecovered_nmi) 
	392                 panic("NMI: Not continuing"); 
	393  
	394         pr_emerg("Dazed and confused, but trying to continue\n");
		    *kmsg_dump(NMI);*
	395 }

>>
>> I felt that the spin_trylock() approach was less horrid than this.  I
>> assume that the new approach will cause lockdep to go berzerk?
>
>Heh.  Good point.  That is probably a good test case.  Though finding a
>working GHES implementation in the firmware isn't easy these days, making
>it hard to test. :-/

Thank you for supporting my patch.
But I can resend another patch below in accordance with Chen's request.
We can avoid potential deplock issue with this patch.
And this is simpler than trylock approach.

> <snip>
> If(!panic)
> 	spin_lock_irqsave();
>
>       .
>       .
> If(!panic)
> 	spin_unlock_restore();
> <snip>

Seiji

Re: [Dle-develop] [RFC][PATCH -next] make pstore/kmsg_dump run after stopping other cpus in panic path

[Don Z. <dz...@re...>]

On Mon, Oct 17, 2011 at 04:47:15PM -0700, Andrew Morton wrote:
> On Fri, 14 Oct 2011 16:53:05 -0400
> > @@ -131,11 +133,7 @@ static void pstore_dump(struct kmsg_dumper *dumper,
> >  		total += l1_cpy + l2_cpy;
> >  		part++;
> >  	}
> > -	if (in_nmi()) {
> > -		if (is_locked)
> > -			spin_unlock(&psinfo->buf_lock);
> > -	} else
> > -		spin_unlock_irqrestore(&psinfo->buf_lock, flags);
> > +	spin_unlock_irqrestore(&psinfo->buf_lock, flags);
> >  }
> 
> afacit this assumes that (reason == KMSG_DUMP_PANIC) if in_nmi().  Is
> that always the case, and will it always be the case in the future?

I see your point.  For now yes.  The common case for which I think pstore
was designed for was the APEI/GHES case.  Normally when GHES hits an NMI
it stays at the APEI/GHES layer and either uses an irq_workqueue for
recoverable errors or panics on non-recoverable errors.

So currently the only time it reaches the pstore layer is in the panic
case.  Unfortunately, I can't vouch for all the backends that can hook
into pstore.

Perhaps a 'BUG_ON(in_nmi() && reason != KMSG_DUMP_PANIC)'?


> 
> I felt that the spin_trylock() approach was less horrid than this.  I
> assume that the new approach will cause lockdep to go berzerk?

Heh.  Good point.  That is probably a good test case.  Though finding a
working GHES implementation in the firmware isn't easy these days, making
it hard to test. :-/

Cheers,
Don

Re: [Dle-develop] [RFC][PATCH -next] make pstore/kmsg_dump run after stopping other cpus in panic path

[Chen G. <gon...@li...>]

于 2011/10/17 22:10, Seiji Aguchi 写道:
> Hi,
>
> Thank you for giving me a comment.
>
>> I have a stupid question: since you have serialized the process procedure via
>> smp_send_stop, why still using spin_lock_xxx? Maybe preempt_disable/enable is
>> enough?
>
>
> I added spin_lock_init() in panic path for sharing code with other triggers
> such as oops/reboot/emergency_restart because they still need spin_locks.
>
> Do you suggest following code?
>
> <snip>
> If(!panic)
> 	spin_lock_irqsave();
>
>       .
>       .
> If(!panic)
> 	spin_unlock_restore();
> <snip>
>
> I don't stick to current patch.
> So I will resend a patch above if you request.

Yes, it looks more readable.

+	if (reason == KMSG_DUMP_PANIC)
+		raw_spin_lock_init(&logbuf_lock);

above codes look a little bit confused

Re: [Dle-develop] [RFC][PATCH -next] make pstore/kmsg_dump run after stopping other cpus in panic path

[Andrew M. <ak...@li...>]

On Fri, 14 Oct 2011 16:53:05 -0400
Seiji Aguchi <sei...@hd...> wrote:

> Hi,
>  
>  As Don mentioned in following thread, it would be nice for pstore/kmsg_dump to serialize 
>  panic path and have one cpu running because they can log messages reliably. 
>  
>  https://lkml.org/lkml/2011/10/13/427
>  
>  For realizing this idea, we have to move kmsg_dump below smp_send_stop() and bust some locks 
>  of kmsg_dump/pstore in panic path.
> 
>  This patch does followings.
> 
>   - moving kmsg_dump(KMSG_DUMP_PANIC) below smp_send_stop.
>   - busting logbuf_lock of kmsg_dump() in panic path for avoiding deadlock.
>   - busting psinfo->buf_lock of pstore_dump() in panic path for avoiding deadlock.
> 
> Any comments are welcome.
>
> ...
>
> --- a/fs/pstore/platform.c
> +++ b/fs/pstore/platform.c
> @@ -90,19 +90,21 @@ static void pstore_dump(struct kmsg_dumper *dumper,
>  	int		hsize, ret;
>  	unsigned int	part = 1;
>  	unsigned long	flags = 0;
> -	int		is_locked = 0;
>  
>  	if (reason < ARRAY_SIZE(reason_str))
>  		why = reason_str[reason];
>  	else
>  		why = "Unknown";
>  
> -	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);
> +	/*
> +	 * pstore_dump() is called after smp_send_stop() in panic path.
> +	 * So, spin_lock should be bust for avoiding deadlock.
> +	 */
> +	if (reason == KMSG_DUMP_PANIC)
> +		spin_lock_init(&psinfo->buf_lock);
> +
> +	spin_lock_irqsave(&psinfo->buf_lock, flags);
> +
>  	oopscount++;
>  	while (total < kmsg_bytes) {
>  		dst = psinfo->buf;
> @@ -131,11 +133,7 @@ static void pstore_dump(struct kmsg_dumper *dumper,
>  		total += l1_cpy + l2_cpy;
>  		part++;
>  	}
> -	if (in_nmi()) {
> -		if (is_locked)
> -			spin_unlock(&psinfo->buf_lock);
> -	} else
> -		spin_unlock_irqrestore(&psinfo->buf_lock, flags);
> +	spin_unlock_irqrestore(&psinfo->buf_lock, flags);
>  }

afacit this assumes that (reason == KMSG_DUMP_PANIC) if in_nmi().  Is
that always the case, and will it always be the case in the future?

I felt that the spin_trylock() approach was less horrid than this.  I
assume that the new approach will cause lockdep to go berzerk?

> --- a/kernel/printk.c
> +++ b/kernel/printk.c
> @@ -1732,6 +1732,13 @@ void kmsg_dump(enum kmsg_dump_reason reason)
>  	unsigned long l1, l2;
>  	unsigned long flags;
>  
> +	/*
> +	 *  kmsg_dump() is called after smp_send_stop() in panic path.
> +	 *  So, spin_lock should be bust for avoiding deadlock.
> +	 */
> +	if (reason == KMSG_DUMP_PANIC)
> +		raw_spin_lock_init(&logbuf_lock);
> +
>  	/* Theoretically, the log could move on after we do this, but
>  	   there's not a lot we can do about that. The new messages
>  	   will overwrite the start of what we dump. */

I suggest you do some research into bust_spinlocks() and how it has
changed over time.  I think that code used to fiddle with log levels
and once upon a time it might have fiddled with logbuf_lock.

Re: [Dle-develop] [RFC][PATCH -next] make pstore/kmsg_dump run after stopping other cpus in panic path

[Seiji A. <sei...@hd...>]

Hi,

I agree with Tony's concern.
But as Don told,  the best way to go proceed is fixing backend drivers step by step.

Seiji


>-----Original Message-----
>From: Don Zickus [mailto:dz...@re...]
>Sent: Monday, October 17, 2011 1:22 PM
>To: Luck, Tony
>Cc: Seiji Aguchi; lin...@vg...; Matthew Garrett; Vivek Goyal; Chen, Gong; Andrew Morton; Brown, Len; Huang,
>Ying; ak...@li...; hu...@ch...; mi...@el...; jm...@na...; a.p...@ch...;
>nam...@gm...; dle...@li...; Satoru Moriya
>Subject: Re: [RFC][PATCH -next] make pstore/kmsg_dump run after stopping other cpus in panic path
>
>On Mon, Oct 17, 2011 at 09:56:50AM -0700, Luck, Tony wrote:
>> > All this lock busting probably isn't pretty and causes one to reflect what
>> > is going on here.  But as long as we are going to keep the kmsg_dump
>> > design, changes like this seem necessary to make sure the locking stays
>> > sane(r) for now.
>>
>> So should we let the back-end know that locks have been busted?  I worry
>> that we'll get through the pstore layer by blasting away at any locks that
>> get in our way - but then the backend (which may well have been written on
>> the assumption that pstore serialized calls to it) will not do anything
>> useful (and may cause its own hang).
>
>I was kinda alluding to something like that, when I said we probably need
>follow on patches to clean up the backend.  But maybe it would be smarter
>to set a flag in pstore to let the backend know we busted the locks
>instead of letting them do panic checks themselves.  I agree with your
>concerns.
>
>I really can't think of a good overall solution other than slowly
>step-by-step untangle things by making subtle changes, this round being
>the serialization of kmsg_dump().
>
>My brain is to small to figure this out.  I keep thinking about making an
>ascii art diagram to see all the various paths and their contexts, but
>then I keep finding more interesting things to do. :-)
>
>Perhaps we should do that and make some rules about what the back-end can
>and can not do when plugging into kmsg_dump.
>
>Cheers,
>Don

Re: [Dle-develop] [RFC][PATCH -next] make pstore/kmsg_dump run after stopping other cpus in panic path

[Don Z. <dz...@re...>]

On Mon, Oct 17, 2011 at 09:56:50AM -0700, Luck, Tony wrote:
> > All this lock busting probably isn't pretty and causes one to reflect what
> > is going on here.  But as long as we are going to keep the kmsg_dump
> > design, changes like this seem necessary to make sure the locking stays
> > sane(r) for now.
> 
> So should we let the back-end know that locks have been busted?  I worry
> that we'll get through the pstore layer by blasting away at any locks that
> get in our way - but then the backend (which may well have been written on
> the assumption that pstore serialized calls to it) will not do anything
> useful (and may cause its own hang).

I was kinda alluding to something like that, when I said we probably need
follow on patches to clean up the backend.  But maybe it would be smarter
to set a flag in pstore to let the backend know we busted the locks
instead of letting them do panic checks themselves.  I agree with your
concerns.

I really can't think of a good overall solution other than slowly
step-by-step untangle things by making subtle changes, this round being
the serialization of kmsg_dump().

My brain is to small to figure this out.  I keep thinking about making an
ascii art diagram to see all the various paths and their contexts, but
then I keep finding more interesting things to do. :-)

Perhaps we should do that and make some rules about what the back-end can
and can not do when plugging into kmsg_dump.

Cheers,
Don

Re: [Dle-develop] [RFC][PATCH -next] make pstore/kmsg_dump run after stopping other cpus in panic path

[Luck, T. <ton...@in...>]

> All this lock busting probably isn't pretty and causes one to reflect what
> is going on here.  But as long as we are going to keep the kmsg_dump
> design, changes like this seem necessary to make sure the locking stays
> sane(r) for now.

So should we let the back-end know that locks have been busted?  I worry
that we'll get through the pstore layer by blasting away at any locks that
get in our way - but then the backend (which may well have been written on
the assumption that pstore serialized calls to it) will not do anything
useful (and may cause its own hang).

-Tony

Re: [Dle-develop] [RFC][PATCH -next] make pstore/kmsg_dump run after stopping other cpus in panic path

[Don Z. <dz...@re...>]

On Fri, Oct 14, 2011 at 04:53:05PM -0400, Seiji Aguchi wrote:
> Hi,
>  
>  As Don mentioned in following thread, it would be nice for pstore/kmsg_dump to serialize 
>  panic path and have one cpu running because they can log messages reliably. 
>  
>  https://lkml.org/lkml/2011/10/13/427
>  
>  For realizing this idea, we have to move kmsg_dump below smp_send_stop() and bust some locks 
>  of kmsg_dump/pstore in panic path.
> 
>  This patch does followings.
> 
>   - moving kmsg_dump(KMSG_DUMP_PANIC) below smp_send_stop.
>   - busting logbuf_lock of kmsg_dump() in panic path for avoiding deadlock.
>   - busting psinfo->buf_lock of pstore_dump() in panic path for avoiding deadlock.
> 
> Any comments are welcome.

I think I am ok with this, just some comments below.

> 
>  Signed-off-by: Seiji Aguchi <sei...@hd...>
> 
> ---
>  fs/pstore/platform.c |   22 ++++++++++------------
>  kernel/panic.c       |    4 ++--
>  kernel/printk.c      |    7 +++++++
>  3 files changed, 19 insertions(+), 14 deletions(-)
> 
> diff --git a/fs/pstore/platform.c b/fs/pstore/platform.c
> index 2bd620f..e73d940 100644
> --- a/fs/pstore/platform.c
> +++ b/fs/pstore/platform.c
> @@ -90,19 +90,21 @@ static void pstore_dump(struct kmsg_dumper *dumper,
>  	int		hsize, ret;
>  	unsigned int	part = 1;
>  	unsigned long	flags = 0;
> -	int		is_locked = 0;
>  
>  	if (reason < ARRAY_SIZE(reason_str))
>  		why = reason_str[reason];
>  	else
>  		why = "Unknown";
>  
> -	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);
> +	/*
> +	 * pstore_dump() is called after smp_send_stop() in panic path.
> +	 * So, spin_lock should be bust for avoiding deadlock.
> +	 */
> +	if (reason == KMSG_DUMP_PANIC)
> +		spin_lock_init(&psinfo->buf_lock);
> +
> +	spin_lock_irqsave(&psinfo->buf_lock, flags);
> +
>  	oopscount++;
>  	while (total < kmsg_bytes) {
>  		dst = psinfo->buf;
> @@ -131,11 +133,7 @@ static void pstore_dump(struct kmsg_dumper *dumper,
>  		total += l1_cpy + l2_cpy;
>  		part++;
>  	}
> -	if (in_nmi()) {
> -		if (is_locked)
> -			spin_unlock(&psinfo->buf_lock);
> -	} else
> -		spin_unlock_irqrestore(&psinfo->buf_lock, flags);
> +	spin_unlock_irqrestore(&psinfo->buf_lock, flags);
>  }

My original problem was the NMI path was calling panic and thus causing
these locking problems.  With the change below, which allows the change
above, I believe the NMI case is covered (because this path is only called
by NMI during panic).  This makes my previous patch (accepted by Tony)
probably unnecessary if we go with this patch.

As for the need for using spin_lock_init vs just skipping the locking, I
don't have a preference, nor know what the correct usage is for these
things.  I suppose this patch does the proper thing.

>  
>  static struct kmsg_dumper pstore_dumper = {
> diff --git a/kernel/panic.c b/kernel/panic.c
> index d7bb697..41bf6ad 100644
> --- a/kernel/panic.c
> +++ b/kernel/panic.c
> @@ -88,8 +88,6 @@ NORET_TYPE void panic(const char * fmt, ...)
>  	 */
>  	crash_kexec(NULL);
>  
> -	kmsg_dump(KMSG_DUMP_PANIC);
> -
>  	/*
>  	 * Note smp_send_stop is the usual smp shutdown function, which
>  	 * unfortunately means it may not be hardened to work in a panic
> @@ -97,6 +95,8 @@ NORET_TYPE void panic(const char * fmt, ...)
>  	 */
>  	smp_send_stop();
>  
> +	kmsg_dump(KMSG_DUMP_PANIC);
> +
>  	atomic_notifier_call_chain(&panic_notifier_list, 0, buf);
>  
>  	bust_spinlocks(0);

Yes, this is what Seiji and I talked about previously based on Vivek's
suggestion.  This can only work on x86 if we pick up my 'using NMI in stop
cpu path' patch from last week.

https://lkml.org/lkml/2011/10/13/426

Otherwise, there is no guarantee all the cpus stop and we can still end up
in data corruption depending on the backend being used.

> diff --git a/kernel/printk.c b/kernel/printk.c
> index 1455a0d..e1e57db 100644
> --- a/kernel/printk.c
> +++ b/kernel/printk.c
> @@ -1732,6 +1732,13 @@ void kmsg_dump(enum kmsg_dump_reason reason)
>  	unsigned long l1, l2;
>  	unsigned long flags;
>  
> +	/*
> +	 *  kmsg_dump() is called after smp_send_stop() in panic path.
> +	 *  So, spin_lock should be bust for avoiding deadlock.
> +	 */
> +	if (reason == KMSG_DUMP_PANIC)
> +		raw_spin_lock_init(&logbuf_lock);
> +
>  	/* Theoretically, the log could move on after we do this, but
>  	   there's not a lot we can do about that. The new messages
>  	   will overwrite the start of what we dump. */
> -- 

The just adds more lock busting based on the movement of kmsg_dump() in
the panic path.

There is still more lock busting to do in the various backends, but this
patch provides the necessary first steps.

All this lock busting probably isn't pretty and causes one to reflect what
is going on here.  But as long as we are going to keep the kmsg_dump
design, changes like this seem necessary to make sure the locking stays
sane(r) for now.

Acked-by: Don Zickus <dz...@re...>