[PATCH] 2.6 PPC64: lockfix for rtas error log (third-times-a-charm?)]

[PATCH] 2.6 PPC64: lockfix for rtas error log (third-times-a-charm?)]

[linas]

> Missed the patch again...  :)
Let me try again ... 


On Wed, Jun 30, 2004 at 01:47:29PM -0500, Benjamin Herrenschmidt wrote:
>
> > Well, the problem was that there is no lock that is protecting the
> > use of the single, global buffer.  Adding yet another lock is bad;
> > it makes hunting for deadlocks that much more tedious and difficult;
> > already, finding deadlocks is error-prone, and subject to bit-rot as
> > future hackers update the code.  So instead, the problem can be
easily
> > avoided by not using a global buffer.  The code below mallocs/frees.
> > Its not perf-critcal, so I don't mind malloc overhead.  Would this
> > work for you?  Patch attached below.
>
> I prefer that, but couldn't we move the kmalloc outside of the spinlock
> and so use GFP_KERNEL instead ?

OK,

Upon closer analysis of the code, I see that log_rtas_error()
was incorrectly named, and was being used incorrectly.  The
solution is to get rid of it entirely; see patch below. So:

-- In one case kmalloc must be GFP_ATOMIC because rtas_call()
can happen in any context, incl. irqs.
-- In the other case, I turned it into GFP_KENREL, at the cost
of doing a needless malloc/free in the vast majority of
cases where there is no error.  Small price, as I beleive
that this routine is very rarely called.

Patch below,
Signed-off-by: Linas Vepstas <linas@linas.org>

--linas

--- arch/ppc64/kernel/rtas.c.orig-pre-lockfix	2004-06-29 17:02:12.000000000 -0500
+++ arch/ppc64/kernel/rtas.c	2004-06-30 15:21:08.000000000 -0500
@@ -98,8 +98,14 @@ rtas_token(const char *service)
 }
 
 
+/** Return a copy of the detailed error text associated with the 
+ *  most recent failed call to rtas.  Because the error text 
+ *  might go stale if there are any other intervening rtas calls,
+ *  this routine must be called atomically with whatever produced
+ *  the error (i.e. with rtas.lock still held from the previous call). 
+ */
 static int
-__log_rtas_error(void)
+__fetch_rtas_last_error(void)
 {
 	struct rtas_args err_args, save_args;
 
@@ -126,19 +132,6 @@ __log_rtas_error(void)
 	return err_args.rets[0];
 }
 
-void
-log_rtas_error(void)
-{
-	unsigned long s;
-	int rc;
-
-	spin_lock_irqsave(&rtas.lock, s);
-	rc = __log_rtas_error();
-	spin_unlock_irqrestore(&rtas.lock, s);
-	if (rc == 0)
-		log_error(rtas_err_buf, ERR_TYPE_RTAS_LOG, 0);
-}
-
 int
 rtas_call(int token, int nargs, int nret,
 	  unsigned long *outputs, ...)
@@ -147,6 +140,7 @@ rtas_call(int token, int nargs, int nret
 	int i, logit = 0;
 	unsigned long s;
 	struct rtas_args *rtas_args;
+	char * buff_copy = NULL;
 	int ret;
 
 	PPCDBG(PPCDBG_RTAS, "Entering rtas_call\n");
@@ -181,7 +175,7 @@ rtas_call(int token, int nargs, int nret
 	PPCDBG(PPCDBG_RTAS, "\treturned from rtas ...\n");
 
 	if (rtas_args->rets[0] == -1)
-		logit = (__log_rtas_error() == 0);
+		logit = (__fetch_rtas_last_error() == 0);
 
 	ifppcdebug(PPCDBG_RTAS) {
 		for(i=0; i < nret ;i++)
@@ -193,12 +187,19 @@ rtas_call(int token, int nargs, int nret
 			outputs[i] = rtas_args->rets[i+1];
 	ret = (int)((nret > 0) ? rtas_args->rets[0] : 0);
 
+	/* Log the error in the unlikely case that there was one. */
+	if (unlikely(logit)) {
+		buff_copy = kmalloc (RTAS_ERROR_LOG_MAX, GFP_ATOMIC);
+		memcpy (buff_copy, rtas_err_buf, RTAS_ERROR_LOG_MAX);
+	}
+	
 	/* Gotta do something different here, use global lock for now... */
 	spin_unlock_irqrestore(&rtas.lock, s);
 
-	if (logit)
-		log_error(rtas_err_buf, ERR_TYPE_RTAS_LOG, 0);
-
+	if (buff_copy) {
+		log_error(buff_copy, ERR_TYPE_RTAS_LOG, 0);
+		kfree (buff_copy);
+	}
 	return ret;
 }
 
@@ -460,7 +461,9 @@ asmlinkage int ppc_rtas(struct rtas_args
 {
 	struct rtas_args args;
 	unsigned long flags;
+	char * buff_copy;
 	int nargs;
+	int err_rc;
 
 	if (!capable(CAP_SYS_ADMIN))
 		return -EPERM;
@@ -479,18 +482,30 @@ asmlinkage int ppc_rtas(struct rtas_args
 			   nargs * sizeof(rtas_arg_t)) != 0)
 		return -EFAULT;
 
+	buff_copy = kmalloc (RTAS_ERROR_LOG_MAX, GFP_KERNEL);
+
 	spin_lock_irqsave(&rtas.lock, flags);
 
 	get_paca()->xRtas = args;
 	enter_rtas(__pa(&get_paca()->xRtas));
 	args = get_paca()->xRtas;
 
-	spin_unlock_irqrestore(&rtas.lock, flags);
-
 	args.rets  = (rtas_arg_t *)&(args.args[nargs]);
-	if (args.rets[0] == -1)
-		log_rtas_error();
 
+	if (args.rets[0] == -1) {
+		err_rc = __fetch_rtas_last_error();
+		if (err_rc == 0) {
+			memcpy (buff_copy, rtas_err_buf, RTAS_ERROR_LOG_MAX);
+		}
+	}
+	
+	spin_unlock_irqrestore(&rtas.lock, flags);
+
+	if (err_rc) {
+		log_error(buff_copy, ERR_TYPE_RTAS_LOG, 0);
+	}
+	kfree (buff_copy);
+	
 	/* Copy out args. */
 	if (copy_to_user(uargs->args + nargs,
 			 args.args + nargs,

Re: [PATCH] 2.6 PPC64: lockfix for rtas error log (third-times-a-charm?)]

[Dave Hansen]

On Thu, 2004-07-01 at 12:19, linas@austin.ibm.com wrote:
> +	/* Log the error in the unlikely case that there was one. */
> +	if (unlikely(logit)) {
> +		buff_copy = kmalloc (RTAS_ERROR_LOG_MAX, GFP_ATOMIC);
> +		memcpy (buff_copy, rtas_err_buf, RTAS_ERROR_LOG_MAX);
> +	}

You forgot to check the allocation for failure.

-- Dave

Re: [PATCH] 2.6 PPC64: lockfix for rtas error log (third-times-a-charm?)]

[linas]

On Thu, Jul 01, 2004 at 12:49:16PM -0700, Dave Hansen wrote:
> 
> You forgot to check the allocation for failure.

Ooops.  Here's another one.

------------------------------------------

> Upon closer analysis of the code, I see that log_rtas_error()
> was incorrectly named, and was being used incorrectly.  The
> solution is to get rid of it entirely; see patch below. So:
> 
> -- In one case kmalloc must be GFP_ATOMIC because rtas_call()
> can happen in any context, incl. irqs.
> -- In the other case, I turned it into GFP_KENREL, at the cost
> of doing a needless malloc/free in the vast majority of
> cases where there is no error.  Small price, as I beleive
> that this routine is very rarely called.
> 
> Patch below,
> Signed-off-by: Linas Vepstas <linas@linas.org>
> 

--- arch/ppc64/kernel/rtas.c.orig-pre-lockfix	2004-06-29 17:02:12.000000000 -0500
+++ arch/ppc64/kernel/rtas.c	2004-07-01 15:26:34.000000000 -0500
@@ -98,8 +98,14 @@ rtas_token(const char *service)
 }
 
 
+/** Return a copy of the detailed error text associated with the 
+ *  most recent failed call to rtas.  Because the error text 
+ *  might go stale if there are any other intervening rtas calls,
+ *  this routine must be called atomically with whatever produced
+ *  the error (i.e. with rtas.lock still held from the previous call). 
+ */
 static int
-__log_rtas_error(void)
+__fetch_rtas_last_error(void)
 {
 	struct rtas_args err_args, save_args;
 
@@ -126,19 +132,6 @@ __log_rtas_error(void)
 	return err_args.rets[0];
 }
 
-void
-log_rtas_error(void)
-{
-	unsigned long s;
-	int rc;
-
-	spin_lock_irqsave(&rtas.lock, s);
-	rc = __log_rtas_error();
-	spin_unlock_irqrestore(&rtas.lock, s);
-	if (rc == 0)
-		log_error(rtas_err_buf, ERR_TYPE_RTAS_LOG, 0);
-}
-
 int
 rtas_call(int token, int nargs, int nret,
 	  unsigned long *outputs, ...)
@@ -147,6 +140,7 @@ rtas_call(int token, int nargs, int nret
 	int i, logit = 0;
 	unsigned long s;
 	struct rtas_args *rtas_args;
+	char * buff_copy = NULL;
 	int ret;
 
 	PPCDBG(PPCDBG_RTAS, "Entering rtas_call\n");
@@ -181,7 +175,7 @@ rtas_call(int token, int nargs, int nret
 	PPCDBG(PPCDBG_RTAS, "\treturned from rtas ...\n");
 
 	if (rtas_args->rets[0] == -1)
-		logit = (__log_rtas_error() == 0);
+		logit = (__fetch_rtas_last_error() == 0);
 
 	ifppcdebug(PPCDBG_RTAS) {
 		for(i=0; i < nret ;i++)
@@ -193,12 +187,21 @@ rtas_call(int token, int nargs, int nret
 			outputs[i] = rtas_args->rets[i+1];
 	ret = (int)((nret > 0) ? rtas_args->rets[0] : 0);
 
+	/* Log the error in the unlikely case that there was one. */
+	if (unlikely(logit)) {
+		buff_copy = kmalloc (RTAS_ERROR_LOG_MAX, GFP_ATOMIC);
+		if (buff_copy) {
+			memcpy (buff_copy, rtas_err_buf, RTAS_ERROR_LOG_MAX);
+		}
+	}
+	
 	/* Gotta do something different here, use global lock for now... */
 	spin_unlock_irqrestore(&rtas.lock, s);
 
-	if (logit)
-		log_error(rtas_err_buf, ERR_TYPE_RTAS_LOG, 0);
-
+	if (buff_copy) {
+		log_error(buff_copy, ERR_TYPE_RTAS_LOG, 0);
+		kfree (buff_copy);
+	}
 	return ret;
 }
 
@@ -460,7 +463,9 @@ asmlinkage int ppc_rtas(struct rtas_args
 {
 	struct rtas_args args;
 	unsigned long flags;
+	char * buff_copy;
 	int nargs;
+	int err_rc;
 
 	if (!capable(CAP_SYS_ADMIN))
 		return -EPERM;
@@ -479,18 +484,32 @@ asmlinkage int ppc_rtas(struct rtas_args
 			   nargs * sizeof(rtas_arg_t)) != 0)
 		return -EFAULT;
 
+	buff_copy = kmalloc (RTAS_ERROR_LOG_MAX, GFP_KERNEL);
+
 	spin_lock_irqsave(&rtas.lock, flags);
 
 	get_paca()->xRtas = args;
 	enter_rtas(__pa(&get_paca()->xRtas));
 	args = get_paca()->xRtas;
 
-	spin_unlock_irqrestore(&rtas.lock, flags);
-
 	args.rets  = (rtas_arg_t *)&(args.args[nargs]);
-	if (args.rets[0] == -1)
-		log_rtas_error();
 
+	if (args.rets[0] == -1) {
+		err_rc = __fetch_rtas_last_error();
+		if ((err_rc == 0) && buff_copy) {
+			memcpy (buff_copy, rtas_err_buf, RTAS_ERROR_LOG_MAX);
+		}
+	}
+	
+	spin_unlock_irqrestore(&rtas.lock, flags);
+
+	if (buff_copy) {
+		if ((args.rets[0] == -1) && (err_rc == 0)) {
+			log_error(buff_copy, ERR_TYPE_RTAS_LOG, 0);
+		}
+		kfree (buff_copy);
+	}
+	
 	/* Copy out args. */
 	if (copy_to_user(uargs->args + nargs,
 			 args.args + nargs,

Re: [PATCH] 2.6 PPC64: lockfix for rtas error log (third-times-a-charm?)]

[Greg KH]

On Thu, Jul 01, 2004 at 03:31:17PM -0500, linas@austin.ibm.com wrote:
> +	/* Log the error in the unlikely case that there was one. */
> +	if (unlikely(logit)) {
> +		buff_copy = kmalloc (RTAS_ERROR_LOG_MAX, GFP_ATOMIC);
> +		if (buff_copy) {
> +			memcpy (buff_copy, rtas_err_buf, RTAS_ERROR_LOG_MAX);
> +		}
> +	}
> +	

The extra space before the '(' isn't needed, as the rest of this file
shows...

And shouldn't you return -ENOMEM if you are out of memory, and can't log
the message?

thanks,

greg k-h

Re: [PATCH] 2.6 PPC64: lockfix for rtas error log (third-times-a-charm?)]

[linas]

On Thu, Jul 01, 2004 at 01:39:38PM -0700, Greg KH wrote:
> 
> And shouldn't you return -ENOMEM if you are out of memory, and can't log
> the message?

The current architected interface for this routine is to return
the error code as generated by firmware, and not an error code that
might be gen'ed during call execution.  If we change this convention,
then we'd have to audit all 68 uses of this routine to see if any
are affected, and fix the ones that are.  This is a potentially 
error-prone process. Also, the likelyhood of having a failed rtas
call is supposed to be very small (ideally never), to hava a failed
call *and* be out of memory to record the failure seems dim ... 
the benefit doesn't seem worth it.


--linas

[PATCH] PPC64: lockfix for rtas error log

[linas]

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


Paul, 

Could you please apply the following path to the ameslab tree, and/or 
forward it to the main 2.6 kernel maintainers.

This patch moves the location of a lock in order to protect
the contents of a buffer until it has been copied to its final
destination. Prior to this, a race existed whereby the buffer
could be filled even while it was being emptied.

Signed-off-by: Linas Vepstas <linas@linas.org>

--linas


[-- Attachment #2: rtas-erbbuf-lockfix.patch --]
[-- Type: text/plain, Size: 857 bytes --]

--- arch/ppc64/kernel/rtas.c.orig-pre-lockfix	2004-06-29 17:02:12.000000000 -0500
+++ arch/ppc64/kernel/rtas.c	2004-06-29 17:14:05.000000000 -0500
@@ -134,9 +134,10 @@ log_rtas_error(void)
 
 	spin_lock_irqsave(&rtas.lock, s);
 	rc = __log_rtas_error();
-	spin_unlock_irqrestore(&rtas.lock, s);
-	if (rc == 0)
+	if (rc == 0) {
 		log_error(rtas_err_buf, ERR_TYPE_RTAS_LOG, 0);
+	}
+	spin_unlock_irqrestore(&rtas.lock, s);
 }
 
 int
@@ -193,12 +194,13 @@ rtas_call(int token, int nargs, int nret
 			outputs[i] = rtas_args->rets[i+1];
 	ret = (int)((nret > 0) ? rtas_args->rets[0] : 0);
 
+	if (logit) {
+		log_error(rtas_err_buf, ERR_TYPE_RTAS_LOG, 0);
+	}
+	
 	/* Gotta do something different here, use global lock for now... */
 	spin_unlock_irqrestore(&rtas.lock, s);
 
-	if (logit)
-		log_error(rtas_err_buf, ERR_TYPE_RTAS_LOG, 0);
-
 	return ret;
 }
 

Re: [PATCH] PPC64: lockfix for rtas error log

[Benjamin Herrenschmidt]

On Tue, 2004-06-29 at 17:50, linas@austin.ibm.com wrote:
> Paul,
> 
> Could you please apply the following path to the ameslab tree, and/or
> forward it to the main 2.6 kernel maintainers.
> 
> This patch moves the location of a lock in order to protect
> the contents of a buffer until it has been copied to its final
> destination. Prior to this, a race existed whereby the buffer
> could be filled even while it was being emptied.

Hrm....

That's bad, I moved that out of the lock on purpose to avoid deadlocks,
I think ppc_md.log_error can take the rtas lock again (nvram). We need to
take a separate lock for the err buf if that function can be called
concurrently I suppose.

Ben.

Re: [PATCH] PPC64: lockfix for rtas error log

[linas]

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

On Tue, Jun 29, 2004 at 08:44:26PM -0500, Benjamin Herrenschmidt wrote:
> On Tue, 2004-06-29 at 17:50, linas@austin.ibm.com wrote:
> > Paul,
> > 
> > Could you please apply the following path to the ameslab tree, and/or
> > forward it to the main 2.6 kernel maintainers.
> > 
> > This patch moves the location of a lock in order to protect
> > the contents of a buffer until it has been copied to its final
> > destination. Prior to this, a race existed whereby the buffer
> > could be filled even while it was being emptied.
> 
> Hrm....
> 
> That's bad, I moved that out of the lock on purpose to avoid deadlocks,

I looked for deadlocks, but didn't see anything obvious.  I'll take your
word, though.

> I think ppc_md.log_error can take the rtas lock again (nvram). We need to
> take a separate lock for the err buf if that function can be called
> concurrently I suppose.

Well, the problem was that there is no lock that is protecting the 
use of the single, global buffer.  Adding yet another lock is bad;
it makes hunting for deadlocks that much more tedious and difficult;
already, finding deadlocks is error-prone, and subject to bit-rot as 
future hackers update the code.  So instead, the problem can be easily 
avoided by not using a global buffer.  The code below mallocs/frees.
Its not perf-critcal, so I don't mind malloc overhead.  Would this
work for you?  Patch attached below.

Signed-off-by: Linas Vepstas <linas@linas.org>

--linas




[-- Attachment #2: rtas-lock-malloc.patch --]
[-- Type: text/plain, Size: 1458 bytes --]

--- arch/ppc64/kernel/rtas.c.orig-pre-lockfix	2004-06-29 17:02:12.000000000 -0500
+++ arch/ppc64/kernel/rtas.c	2004-06-30 12:26:51.000000000 -0500
@@ -131,12 +131,20 @@ log_rtas_error(void)
 {
 	unsigned long s;
 	int rc;
+	char * buff_copy = NULL;
 
 	spin_lock_irqsave(&rtas.lock, s);
 	rc = __log_rtas_error();
+	if (rc == 0) {
+		buff_copy = kmalloc (RTAS_ERROR_LOG_MAX, GFP_ATOMIC);
+		memcpy (buff_copy, rtas_err_buf, RTAS_ERROR_LOG_MAX);
+	}
 	spin_unlock_irqrestore(&rtas.lock, s);
-	if (rc == 0)
-		log_error(rtas_err_buf, ERR_TYPE_RTAS_LOG, 0);
+
+	if (buff_copy) {
+		log_error(buff_copy, ERR_TYPE_RTAS_LOG, 0);
+		kfree (buff_copy);
+	}
 }
 
 int
@@ -147,6 +155,7 @@ rtas_call(int token, int nargs, int nret
 	int i, logit = 0;
 	unsigned long s;
 	struct rtas_args *rtas_args;
+	char * buff_copy = NULL;
 	int ret;
 
 	PPCDBG(PPCDBG_RTAS, "Entering rtas_call\n");
@@ -193,12 +202,18 @@ rtas_call(int token, int nargs, int nret
 			outputs[i] = rtas_args->rets[i+1];
 	ret = (int)((nret > 0) ? rtas_args->rets[0] : 0);
 
+	if (logit) {
+		buff_copy = kmalloc (RTAS_ERROR_LOG_MAX, GFP_ATOMIC);
+		memcpy (buff_copy, rtas_err_buf, RTAS_ERROR_LOG_MAX);
+	}
+	
 	/* Gotta do something different here, use global lock for now... */
 	spin_unlock_irqrestore(&rtas.lock, s);
 
-	if (logit)
-		log_error(rtas_err_buf, ERR_TYPE_RTAS_LOG, 0);
-
+	if (buff_copy) {
+		log_error(buff_copy, ERR_TYPE_RTAS_LOG, 0);
+		kfree (buff_copy);
+	}
 	return ret;
 }
 

Re: [PATCH] PPC64: lockfix for rtas error log

[Benjamin Herrenschmidt]

> Well, the problem was that there is no lock that is protecting the
> use of the single, global buffer.  Adding yet another lock is bad;
> it makes hunting for deadlocks that much more tedious and difficult;
> already, finding deadlocks is error-prone, and subject to bit-rot as
> future hackers update the code.  So instead, the problem can be easily
> avoided by not using a global buffer.  The code below mallocs/frees.
> Its not perf-critcal, so I don't mind malloc overhead.  Would this
> work for you?  Patch attached below.

I prefer that, but couldn't we move the kmalloc outside of the spinlock
and so use GFP_KERNEL instead ?

Ben.

[PATCH] 2.6 PPC64: lockfix for rtas error log (third-times-a-charm?)

[linas]

On Wed, Jun 30, 2004 at 01:47:29PM -0500, Benjamin Herrenschmidt wrote:
> 
> > Well, the problem was that there is no lock that is protecting the
> > use of the single, global buffer.  Adding yet another lock is bad;
> > it makes hunting for deadlocks that much more tedious and difficult;
> > already, finding deadlocks is error-prone, and subject to bit-rot as
> > future hackers update the code.  So instead, the problem can be easily
> > avoided by not using a global buffer.  The code below mallocs/frees.
> > Its not perf-critcal, so I don't mind malloc overhead.  Would this
> > work for you?  Patch attached below.
> 
> I prefer that, but couldn't we move the kmalloc outside of the spinlock
> and so use GFP_KERNEL instead ?

OK,

Upon closer analysis of the code, I see that log_rtas_error() 
was incorrectly named, and was being used incorrectly.  The 
solution is to get rid of it entirely; see patch below. So:

-- In one case kmalloc must be GFP_ATOMIC because rtas_call()
   can happen in any context, incl. irqs.
-- In the other case, I turned it into GFP_KENREL, at the cost
   of doing a needless malloc/free in the vast majority of 
   cases where there is no error.  Small price, as I beleive
   that this routine is very rarely called.

Patch below, 
Signed-off-by: Linas Vepstas <linas@linas.org>

--linas