[RFC][PATCH v3 2/3] Skip spin_locks in panic case and add WARN_ON()

[RFC][PATCH v3 2/3] Skip spin_locks in panic case and add WARN_ON()

[Seiji Aguchi]

Patch Description:
   - Skip spin_locks in panic case in both kmsg_dump() and pstore_dump() because they are 
     serialized via smp_send_stop

   - Add WARN_ON() in "in_nmi() and !panic" case into kmsg_dump(). Currently, this case never 
     happens because only kmsg_dump(KMSG_DUMP_PANIC) is called in NMI case.
     But if someone adds new kmsg_dump() into NMI path in the future, kmsg_dump() may deadlock. 
     We can trap it and complain with this WARN_ON().
     

 With this patch, kmsg_dump()/pstore_dump() work as follows.
   panic case (KMSG_DUMP_PANIC):
     - don't take lock because they are serialized.

   not panic case (KMSG_DUMP_OOPS/KMSG_DUMP_EMERG/KMSG_DUMP_RESTART/KMSG_DUMP_HALT):
     - take locks normally
 
 Regarding as NMI case,
    - kmsg_dump()/pstore_dump() don't take locks, so deadlock issue will not happen
      because kmsg_dump() is called in just panic case with current implementation.
    - If someone adds new kmsg_dump() into NMI path, WARN_ON() is called.
      So we can trap it and ask to fix it.

 Signed-off-by: Seiji Aguchi <seiji.aguchi@hds.com>

---
 fs/pstore/platform.c |   16 ++++++----------
 kernel/printk.c      |   13 +++++++++++--
 2 files changed, 17 insertions(+), 12 deletions(-)

diff --git a/fs/pstore/platform.c b/fs/pstore/platform.c
index 57bbf90..823669e 100644
--- a/fs/pstore/platform.c
+++ b/fs/pstore/platform.c
@@ -90,18 +90,17 @@ 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
+	/*
+	 * pstore_dump() is serialized in panic path.
+	 * So, we don't need to take any locks.
+	 */
+	if (reason != KMSG_DUMP_PANIC)
 		spin_lock_irqsave(&psinfo->buf_lock, flags);
 	oopscount++;
 	while (total < kmsg_bytes) {
@@ -131,10 +130,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
+	if (reason != KMSG_DUMP_PANIC)
 		spin_unlock_irqrestore(&psinfo->buf_lock, flags);
 }
 
diff --git a/kernel/printk.c b/kernel/printk.c
index 1455a0d..bc5ac61 100644
--- a/kernel/printk.c
+++ b/kernel/printk.c
@@ -1732,13 +1732,22 @@ void kmsg_dump(enum kmsg_dump_reason reason)
 	unsigned long l1, l2;
 	unsigned long flags;
 
+	WARN_ON(in_nmi() && reason != KMSG_DUMP_PANIC);
+
 	/* 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(KMSG_DUMP_PANIC) is serialized.
+	 * So, we don't need to take any locks.
+	 */
+	if (reason != KMSG_DUMP_PANIC)
+		raw_spin_lock_irqsave(&logbuf_lock, flags);
 	end = log_end & LOG_BUF_MASK;
 	chars = logged_chars;
-	raw_spin_unlock_irqrestore(&logbuf_lock, flags);
+	if (reason != KMSG_DUMP_PANIC)
+		raw_spin_unlock_irqrestore(&logbuf_lock, flags);
 
 	if (chars > end) {
 		s1 = log_buf + log_buf_len - chars + end;
-- 
1.7.1

Re: [RFC][PATCH v3 2/3] Skip spin_locks in panic case and add WARN_ON()

[Don Zickus]

On Fri, Dec 02, 2011 at 05:10:26PM -0500, Seiji Aguchi wrote:
> Patch Description:
>    - Skip spin_locks in panic case in both kmsg_dump() and pstore_dump() because they are 
>      serialized via smp_send_stop
> 
>    - Add WARN_ON() in "in_nmi() and !panic" case into kmsg_dump(). Currently, this case never 
>      happens because only kmsg_dump(KMSG_DUMP_PANIC) is called in NMI case.
>      But if someone adds new kmsg_dump() into NMI path in the future, kmsg_dump() may deadlock. 
>      We can trap it and complain with this WARN_ON().
>      
> 
>  With this patch, kmsg_dump()/pstore_dump() work as follows.
>    panic case (KMSG_DUMP_PANIC):
>      - don't take lock because they are serialized.
> 
>    not panic case (KMSG_DUMP_OOPS/KMSG_DUMP_EMERG/KMSG_DUMP_RESTART/KMSG_DUMP_HALT):
>      - take locks normally
>  
>  Regarding as NMI case,
>     - kmsg_dump()/pstore_dump() don't take locks, so deadlock issue will not happen
>       because kmsg_dump() is called in just panic case with current implementation.
>     - If someone adds new kmsg_dump() into NMI path, WARN_ON() is called.
>       So we can trap it and ask to fix it.
> 
>  Signed-off-by: Seiji Aguchi <seiji.aguchi@hds.com>
> 
> ---
>  fs/pstore/platform.c |   16 ++++++----------
>  kernel/printk.c      |   13 +++++++++++--
>  2 files changed, 17 insertions(+), 12 deletions(-)
> 
> diff --git a/fs/pstore/platform.c b/fs/pstore/platform.c
> index 57bbf90..823669e 100644
> --- a/fs/pstore/platform.c
> +++ b/fs/pstore/platform.c
> @@ -90,18 +90,17 @@ 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
> +	/*
> +	 * pstore_dump() is serialized in panic path.
> +	 * So, we don't need to take any locks.
> +	 */
> +	if (reason != KMSG_DUMP_PANIC)
>  		spin_lock_irqsave(&psinfo->buf_lock, flags);

This probably won't work because the original check wasn't necessarily for
locking purposes but to see if a lock was already taken in the serialized
path.  If buf_lock is already held, the code may have trouble executing
the backend, hence the pr_err.


>  	oopscount++;
>  	while (total < kmsg_bytes) {
> @@ -131,10 +130,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
> +	if (reason != KMSG_DUMP_PANIC)
>  		spin_unlock_irqrestore(&psinfo->buf_lock, flags);
>  }
>  
> diff --git a/kernel/printk.c b/kernel/printk.c
> index 1455a0d..bc5ac61 100644
> --- a/kernel/printk.c
> +++ b/kernel/printk.c
> @@ -1732,13 +1732,22 @@ void kmsg_dump(enum kmsg_dump_reason reason)
>  	unsigned long l1, l2;
>  	unsigned long flags;
>  
> +	WARN_ON(in_nmi() && reason != KMSG_DUMP_PANIC);
> +

You will need a comment to explain why the above is there.

>  	/* 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(KMSG_DUMP_PANIC) is serialized.
> +	 * So, we don't need to take any locks.
> +	 */
> +	if (reason != KMSG_DUMP_PANIC)
> +		raw_spin_lock_irqsave(&logbuf_lock, flags);
>  	end = log_end & LOG_BUF_MASK;
>  	chars = logged_chars;
> -	raw_spin_unlock_irqrestore(&logbuf_lock, flags);
> +	if (reason != KMSG_DUMP_PANIC)
> +		raw_spin_unlock_irqrestore(&logbuf_lock, flags);
>  
>  	if (chars > end) {
>  		s1 = log_buf + log_buf_len - chars + end;

Cheers,
Don

RE: [RFC][PATCH v3 2/3] Skip spin_locks in panic case and add WARN_ON()

[Seiji Aguchi]

Hi,

>> -	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
>> +	/*
>> +	 * pstore_dump() is serialized in panic path.
>> +	 * So, we don't need to take any locks.
>> +	 */
>> +	if (reason != KMSG_DUMP_PANIC)
>>  		spin_lock_irqsave(&psinfo->buf_lock, flags);
>
>This probably won't work because the original check wasn't necessarily for
>locking purposes but to see if a lock was already taken in the serialized
>path.  If buf_lock is already held, the code may have trouble executing
>the backend, hence the pr_err.

If locking of backend drivers ,such as erst_lock/efivars_lock, was held in serialized path,
the backend drivers may have some troubles.

On the other hand, pstore will not have any trouble with my code because psinfo->buf_lock is protecting 
the memory ,psinfo->buf, which backend driver use to save data and the content of psinfo->buf is
simply overwritten in pstore_dump().

So, pstore can just blindly continue even if psinfo->buf_lock is held in the serialized path.

If there are some troubles in backend drivers, they should be fixed.


I guess you suggest me to add some code checking lock status so that users/developers know 
the reason why pstore failed.
So, I have a comment about that.

If you would like to just check if a lock was already in the serialized path,
"is_spin_locked()" macro is better.
In addition to that, if you would like to let users know the locking status, pr_err() is needed. 
So, the code will be as follows.

 if (reason == KMSG_DUMP_PANIC) {
 	if(is_spin_locked(&psinfo->buf_lock))
 		pr_err("lock is taken.\n");
 else {
 	spin_lock_irqsave(&psinfo->buf_lock, flags);
 }

However, this won't work for this reason.
  - printk() must not be called in serialized path because deadlock of logbuf_lock may cause.
  
Of course, we can avoid deadlock if spin_lock_init(logbuf_lock) is called. But spin_lock_init() 
is not accepted in previous discussion.



>> +	WARN_ON(in_nmi() && reason != KMSG_DUMP_PANIC);
>> +
>
>You will need a comment to explain why the above is there.

I agree. The comment is needed.

Seiji

RE: [RFC][PATCH v3 2/3] Skip spin_locks in panic case and add WARN_ON()

[Luck, Tony]

> if (reason == KMSG_DUMP_PANIC) {
> 	if(is_spin_locked(&psinfo->buf_lock))
> 		pr_err("lock is taken.\n");
> else {
> 	spin_lock_irqsave(&psinfo->buf_lock, flags);
> }
>
> However, this won't work for this reason.
>  - printk() must not be called in serialized path because deadlock of logbuf_lock may cause.

There is also the issue that kmsg has already computed the addresses
of useful pieces in __log_buf at this point - so any printk() we
add here is not going to be saved into pstore.  So a user relying
on pstore to see what happened, won't see any messages we add here.

-Tony

Re: [RFC][PATCH v3 2/3] Skip spin_locks in panic case and add WARN_ON()

[Don Zickus]

On Mon, Dec 12, 2011 at 10:48:52AM -0800, Luck, Tony wrote:
> > if (reason == KMSG_DUMP_PANIC) {
> > 	if(is_spin_locked(&psinfo->buf_lock))
> > 		pr_err("lock is taken.\n");
> > else {
> > 	spin_lock_irqsave(&psinfo->buf_lock, flags);
> > }
> >
> > However, this won't work for this reason.
> >  - printk() must not be called in serialized path because deadlock of logbuf_lock may cause.
> 
> There is also the issue that kmsg has already computed the addresses
> of useful pieces in __log_buf at this point - so any printk() we
> add here is not going to be saved into pstore.  So a user relying
> on pstore to see what happened, won't see any messages we add here.

Ah.  Good point.

Now we have a scenario (though rare), where kmsg_dump can fail to save a
dump because some one already has the lock.  Hitachi's whole goal behind
kmsg_dump is to record every possible reason for rebooting the machine for
inspection on reboot, I think if I understood Seiji privately.

Seiji, has does this failure impact kmsg_dump's goal?

Cheers,
Don

RE: [RFC][PATCH v3 2/3] Skip spin_locks in panic case and add WARN_ON()

[Seiji Aguchi]

Hi,

Thank you for coordinating discussion.

>Hitachi's whole goal behind
>kmsg_dump is to record every possible reason for rebooting the machine for
>inspection on reboot, I think if I understood Seiji privately.

Exactly.

>Now we have a scenario (though rare), where kmsg_dump can fail to save a
>dump because someone already has the lock.
>Seiji, has does this failure impact kmsg_dump's goal?

When we use EFI-enabled system, we can avoid this failure because
,as you can see below(spec of EFI 2.3), kernel in NMI can call set_variable 
runtime service even if previous call is busy.

<snip>
  7.1 Runtime Services Rules and Restrictions
  7.1.1 Exception for Machine Check, INIT, and NMI.
   .
   .
   .
  If the OS determines that the Machine Check is non-recoverable, the OS level handler may 
  ignore the normal restrictions and may invoke the runtime services described in Table 31 even 
  in the case where a previous call was busy. The system firmware will honor the new runtime 
  service call(s) and the operation of the previous interrupted call is not guaranteed. 
  Any interrupted runtime functions will not be restarted.
  The INIT and NMI events follow the same restrictions.
<snip>

So, next steps we should take are as follows.

 - Fix efi_pstore so "efivars->lock" in efi_pstore_write() skips in panic path.

 - Fix smp_send_stop() (or introduce new function call) 
   so that kmsg_dump(KMSG_DUMP_PANIC) is always called in NMI.

   Currently, panicked cpu sends NMI to all cpus other than itself in smp_send_stop() (with Don's patch).
   My suggestion is that panicked cpu sends NMI to itself and then it calls kmsg_dump(KMSG_DUMP_PANIC) in NMI.

Seiji

RE: [RFC][PATCH v3 2/3] Skip spin_locks in panic case and add WARN_ON()

[Luck, Tony]

>  7.1.1 Exception for Machine Check, INIT, and NMI.

I wonder if this section is poorly named ... I suspect that it may really mean
"Exception for fatal situations".  I don't think that the EFI code has any way
to know that one of these events has happened (in theory it could tell that it
was executing a machine check handler if it looked at MCIP bit in MCG_STATUS,
but I doubt that it does that ... INIT/NMI would seem even harder to detect).

>   My suggestion is that panicked cpu sends NMI to itself and then it calls kmsg_dump(KMSG_DUMP_PANIC) in NMI.

So I wonder whether there is any value in the cpu sending an NMI to itself to
meet the exact wording of this section in the spec.

I'll ask an Intel EFI guru whether I'm on target.

-Tony

RE: [RFC][PATCH v3 2/3] Skip spin_locks in panic case and add WARN_ON()

[Seiji Aguchi]

>So I wonder whether there is any value in the cpu sending an NMI to itself to
>meet the exact wording of this section in the spec.
>
>I'll ask an Intel EFI guru whether I'm on target.

Thanks, Tony. I wait for their reply.

Seiji

RE: [RFC][PATCH v3 2/3] Skip spin_locks in panic case and add WARN_ON()

[Luck, Tony]

> I'll ask an Intel EFI guru whether I'm on target.

Got a short note back from the EFI people:

----
The reason the paragraph exists in 7.1.1 is that certain services (as listed
in table 31) are guaranteed to work if you call them a second time when you
have taken an exception in trying to execute them already -- say SetVariable()
face plants with an exception...because of the way our code is designed you
can call it a second time even if the first call that took the exception
didn't succeed.

At any rate, I checked with a couple of the other experts around us and none
of us can see any reason to send yourself an NMI just to preface a call to
a UEFI runtime service.  Thus, our collective opinion is that you are correct
in your interpretation.
----

If you want to discuss this more - they apparently have an external mailing
list some place on TianoCore.org. But this seems pretty clear that we don't
need to self-NMI.

-Tony

RE: [RFC][PATCH v3 2/3] Skip spin_locks in panic case and add WARN_ON()

[Seiji Aguchi]

>But this seems pretty clear that we don't need to self-NMI.

Thank you for your explanation.
Now I understand that we don't need self-NMI and efi_pstore can blindly continue in panic path
because setvariable() will succeed even if the previous call that took the exception didn't succeed.

I will submit an updated patch by removing spin_lock of efi_pstore_write() in panic path.

Seiji