[v3] applesmc: Re-work SMC comms

Commit Message

Brad Campbell Nov. 8, 2020, 1 a.m. UTC

G'day Henrik,

I noticed you'd also loosened up the requirement for SMC_STATUS_BUSY in read_smc(). I assume
that causes problems on the early Macbook. This is revised on the one sent earlier.
If you could test this on your Air1,1 it'd be appreciated.


Commit fff2d0f701e6 ("hwmon: (applesmc) avoid overlong udelay()") introduced
an issue whereby communication with the SMC became unreliable with write
errors like :

[  120.378614] applesmc: send_byte(0x00, 0x0300) fail: 0x40
[  120.378621] applesmc: LKSB: write data fail
[  120.512782] applesmc: send_byte(0x00, 0x0300) fail: 0x40
[  120.512787] applesmc: LKSB: write data fail

The original code appeared to be timing sensitive and was not reliable with
the timing changes in the aforementioned commit.

This patch re-factors the SMC communication to remove the timing 
dependencies and restore function with the changes previously committed.

Tested on : MacbookAir6,2 MacBookPro11,1 iMac12,2

Fixes: fff2d0f701e6 ("hwmon: (applesmc) avoid overlong udelay()")
Reported-by: Andreas Kemnade <[e-mail]>
Tested-by: Andreas Kemnade <[e-mail]> # MacBookAir6,2
Acked-by: Arnd Bergmann <[e-mail]>
Signed-off-by: Brad Campbell <[e-mail]>
Signed-off-by: Henrik Rydberg <[e-mail]>

---
Changelog : 
v1 : Inital attempt
v2 : Address logic and coding style
v3 : Removed some debug hangover. Added tested-by. Modifications for MacBookAir1,1

Comments

Henrik Rydberg Nov. 8, 2020, 8:35 a.m. UTC | #1

Hi Brad,

On 2020-11-08 02:00, Brad Campbell wrote:
> G'day Henrik,
> 
> I noticed you'd also loosened up the requirement for SMC_STATUS_BUSY in read_smc(). I assume
> that causes problems on the early Macbook. This is revised on the one sent earlier.
> If you could test this on your Air1,1 it'd be appreciated.

No, I managed to screw up the patch; you can see that I carefully added 
the same treatment for the read argument, being unsure if the BUSY state 
would remain during the AVAILABLE data phase. I can check that again, 
but unfortunately the patch in this email shows the same problem.

I think it may be worthwhile to rethink the behavior of wait_status() 
here. If one machine shows no change after a certain status bit change, 
then perhaps the others share that behavior, and we are waiting in vain. 
Just imagine how many years of cpu that is, combined. ;-)

Henrik

> 
> Commit fff2d0f701e6 ("hwmon: (applesmc) avoid overlong udelay()") introduced
> an issue whereby communication with the SMC became unreliable with write
> errors like :
> 
> [  120.378614] applesmc: send_byte(0x00, 0x0300) fail: 0x40
> [  120.378621] applesmc: LKSB: write data fail
> [  120.512782] applesmc: send_byte(0x00, 0x0300) fail: 0x40
> [  120.512787] applesmc: LKSB: write data fail
> 
> The original code appeared to be timing sensitive and was not reliable with
> the timing changes in the aforementioned commit.
> 
> This patch re-factors the SMC communication to remove the timing
> dependencies and restore function with the changes previously committed.
> 
> Tested on : MacbookAir6,2 MacBookPro11,1 iMac12,2
> 
> Fixes: fff2d0f701e6 ("hwmon: (applesmc) avoid overlong udelay()")
> Reported-by: Andreas Kemnade <[e-mail]>
> Tested-by: Andreas Kemnade <[e-mail]> # MacBookAir6,2
> Acked-by: Arnd Bergmann <[e-mail]>
> Signed-off-by: Brad Campbell <[e-mail]>
> Signed-off-by: Henrik Rydberg <[e-mail]>
> 
> ---
> Changelog :
> v1 : Inital attempt
> v2 : Address logic and coding style
> v3 : Removed some debug hangover. Added tested-by. Modifications for MacBookAir1,1
> 
> diff --git a/drivers/hwmon/applesmc.c b/drivers/hwmon/applesmc.c
> index a18887990f4a..3e968abb37aa 100644
> --- a/drivers/hwmon/applesmc.c
> +++ b/drivers/hwmon/applesmc.c
> @@ -32,6 +32,7 @@
>   #include <linux/hwmon.h>
>   #include <linux/workqueue.h>
>   #include <linux/err.h>
> +#include <linux/bits.h>
>   
>   /* data port used by Apple SMC */
>   #define APPLESMC_DATA_PORT	0x300
> @@ -42,6 +43,11 @@
>   
>   #define APPLESMC_MAX_DATA_LENGTH 32
>   
> +/* Apple SMC status bits */
> +#define SMC_STATUS_AWAITING_DATA  BIT(0) /* SMC has data waiting */
> +#define SMC_STATUS_IB_CLOSED      BIT(1) /* Will ignore any input */
> +#define SMC_STATUS_BUSY           BIT(2) /* Command in progress */
> +
>   /* wait up to 128 ms for a status change. */
>   #define APPLESMC_MIN_WAIT	0x0010
>   #define APPLESMC_RETRY_WAIT	0x0100
> @@ -151,65 +157,73 @@ static unsigned int key_at_index;
>   static struct workqueue_struct *applesmc_led_wq;
>   
>   /*
> - * wait_read - Wait for a byte to appear on SMC port. Callers must
> - * hold applesmc_lock.
> + * Wait for specific status bits with a mask on the SMC
> + * Used before and after writes, and before reads
>    */
> -static int wait_read(void)
> +
> +static int wait_status(u8 val, u8 mask)
>   {
>   	unsigned long end = jiffies + (APPLESMC_MAX_WAIT * HZ) / USEC_PER_SEC;
>   	u8 status;
>   	int us;
>   
> +	udelay(APPLESMC_MIN_WAIT);
>   	for (us = APPLESMC_MIN_WAIT; us < APPLESMC_MAX_WAIT; us <<= 1) {
> -		usleep_range(us, us * 16);
>   		status = inb(APPLESMC_CMD_PORT);
> -		/* read: wait for smc to settle */
> -		if (status & 0x01)
> +		if ((status & mask) == val)
>   			return 0;
>   		/* timeout: give up */
>   		if (time_after(jiffies, end))
>   			break;
> +		usleep_range(us, us * 16);
>   	}
> -
> -	pr_warn("wait_read() fail: 0x%02x\n", status);
>   	return -EIO;
>   }
>   
>   /*
> - * send_byte - Write to SMC port, retrying when necessary. Callers
> + * send_byte_data - Write to SMC data port. Callers
>    * must hold applesmc_lock.
> + * Parameter skip must be true on the last write of any
> + * command or it'll time out.
>    */
> -static int send_byte(u8 cmd, u16 port)
> +
> +static int send_byte_data(u8 cmd, u16 port, bool skip)
>   {
> -	u8 status;
> -	int us;
> -	unsigned long end = jiffies + (APPLESMC_MAX_WAIT * HZ) / USEC_PER_SEC;
> +	int ret;
>   
> +	ret = wait_status(SMC_STATUS_BUSY, SMC_STATUS_BUSY | SMC_STATUS_IB_CLOSED);
> +	if (ret)
> +		return ret;
>   	outb(cmd, port);
> -	for (us = APPLESMC_MIN_WAIT; us < APPLESMC_MAX_WAIT; us <<= 1) {
> -		usleep_range(us, us * 16);
> -		status = inb(APPLESMC_CMD_PORT);
> -		/* write: wait for smc to settle */
> -		if (status & 0x02)
> -			continue;
> -		/* ready: cmd accepted, return */
> -		if (status & 0x04)
> -			return 0;
> -		/* timeout: give up */
> -		if (time_after(jiffies, end))
> -			break;
> -		/* busy: long wait and resend */
> -		udelay(APPLESMC_RETRY_WAIT);
> -		outb(cmd, port);
> -	}
> +	return wait_status(skip ? 0 : SMC_STATUS_BUSY, SMC_STATUS_BUSY);
> +}
>   
> -	pr_warn("send_byte(0x%02x, 0x%04x) fail: 0x%02x\n", cmd, port, status);
> -	return -EIO;
> +static int send_byte(u8 cmd, u16 port)
> +{
> +	return send_byte_data(cmd, port, false);
>   }
>   
> +/*
> + * send_command - Write a command to the SMC. Callers must hold applesmc_lock.
> + * If SMC is in undefined state, any new command write resets the state machine.
> + */
> +
>   static int send_command(u8 cmd)
>   {
> -	return send_byte(cmd, APPLESMC_CMD_PORT);
> +	int ret;
> +	int i;
> +
> +	for (i = 0; i < 16; i++) {
> +		ret = wait_status(0, SMC_STATUS_IB_CLOSED);
> +		if (ret)
> +			return ret;
> +
> +		outb(cmd, APPLESMC_CMD_PORT);
> +		ret = wait_status(SMC_STATUS_BUSY, SMC_STATUS_BUSY);
> +		if (!ret)
> +			return ret;
> +	}
> +	return -EIO;
>   }
>   
>   static int send_argument(const char *key)
> @@ -239,7 +253,8 @@ static int read_smc(u8 cmd, const char *key, u8 *buffer, u8 len)
>   	}
>   
>   	for (i = 0; i < len; i++) {
> -		if (wait_read()) {
> +		if (wait_status(SMC_STATUS_AWAITING_DATA,
> +				SMC_STATUS_AWAITING_DATA | SMC_STATUS_IB_CLOSED)) {
>   			pr_warn("%.4s: read data[%d] fail\n", key, i);
>   			return -EIO;
>   		}
> @@ -250,7 +265,7 @@ static int read_smc(u8 cmd, const char *key, u8 *buffer, u8 len)
>   	for (i = 0; i < 16; i++) {
>   		udelay(APPLESMC_MIN_WAIT);
>   		status = inb(APPLESMC_CMD_PORT);
> -		if (!(status & 0x01))
> +		if (!(status & SMC_STATUS_AWAITING_DATA))
>   			break;
>   		data = inb(APPLESMC_DATA_PORT);
>   	}
> @@ -275,7 +290,7 @@ static int write_smc(u8 cmd, const char *key, const u8 *buffer, u8 len)
>   	}
>   
>   	for (i = 0; i < len; i++) {
> -		if (send_byte(buffer[i], APPLESMC_DATA_PORT)) {
> +		if (send_byte_data(buffer[i], APPLESMC_DATA_PORT, i == len - 1)) {
>   			pr_warn("%s: write data fail\n", key);
>   			return -EIO;
>   		}
>

Henrik Rydberg Nov. 8, 2020, 10:14 a.m. UTC | #2

On Sun, Nov 08, 2020 at 09:35:28AM +0100, Henrik Rydberg wrote:
> Hi Brad,
> 
> On 2020-11-08 02:00, Brad Campbell wrote:
> > G'day Henrik,
> > 
> > I noticed you'd also loosened up the requirement for SMC_STATUS_BUSY in read_smc(). I assume
> > that causes problems on the early Macbook. This is revised on the one sent earlier.
> > If you could test this on your Air1,1 it'd be appreciated.
> 
> No, I managed to screw up the patch; you can see that I carefully added the
> same treatment for the read argument, being unsure if the BUSY state would
> remain during the AVAILABLE data phase. I can check that again, but
> unfortunately the patch in this email shows the same problem.
> 
> I think it may be worthwhile to rethink the behavior of wait_status() here.
> If one machine shows no change after a certain status bit change, then
> perhaps the others share that behavior, and we are waiting in vain. Just
> imagine how many years of cpu that is, combined. ;-)

Here is a modification along that line.

Compared to your latest version, this one has wait_status() return the
actual status on success. Instead of waiting for BUSY, it waits for
the other status bits, and checks BUSY afterwards. So as not to wait
unneccesarily, the udelay() is placed together with the single
outb(). The return value of send_byte_data() is augmented with
-EAGAIN, which is then used in send_command() to create the resend
loop.

I reach 41 reads per second on the MBA1,1 with this version, which is
getting close to the performance prior to the problems.

From b4405457f4ba07cff7b7e4f48c47668bee176a25 Mon Sep 17 00:00:00 2001
From: Brad Campbell <[e-mail]>
Date: Sun, 8 Nov 2020 12:00:03 +1100
Subject: [PATCH] hwmon: (applesmc) Re-work SMC comms

Commit fff2d0f701e6 ("hwmon: (applesmc) avoid overlong udelay()")
introduced an issue whereby communication with the SMC became
unreliable with write errors like :

[  120.378614] applesmc: send_byte(0x00, 0x0300) fail: 0x40
[  120.378621] applesmc: LKSB: write data fail
[  120.512782] applesmc: send_byte(0x00, 0x0300) fail: 0x40
[  120.512787] applesmc: LKSB: write data fail

The original code appeared to be timing sensitive and was not reliable
with the timing changes in the aforementioned commit.

This patch re-factors the SMC communication to remove the timing
dependencies and restore function with the changes previously
committed.

Tested on : MacbookAir6,2 MacBookPro11,1 iMac12,2, MacBookAir1,1,
MacBookAir3,1

Fixes: fff2d0f701e6 ("hwmon: (applesmc) avoid overlong udelay()")
Reported-by: Andreas Kemnade <[e-mail]>
Tested-by: Andreas Kemnade <[e-mail]> # MacBookAir6,2
Acked-by: Arnd Bergmann <[e-mail]>
Signed-off-by: Brad Campbell <[e-mail]>
Signed-off-by: Henrik Rydberg <[e-mail]>

---
Changelog : 
v1 : Inital attempt
v2 : Address logic and coding style
v3 : Removed some debug hangover. Added tested-by. Modifications for MacBookAir1,1
v4 : Do not expect busy state to appear without other state changes

diff --git a/drivers/hwmon/applesmc.c b/drivers/hwmon/applesmc.c
index a18887990f4a..ea7c66d5788e 100644
--- a/drivers/hwmon/applesmc.c
+++ b/drivers/hwmon/applesmc.c
@@ -32,6 +32,7 @@
 #include <linux/hwmon.h>
 #include <linux/workqueue.h>
 #include <linux/err.h>
+#include <linux/bits.h>
 
 /* data port used by Apple SMC */
 #define APPLESMC_DATA_PORT	0x300
@@ -42,6 +43,11 @@
 
 #define APPLESMC_MAX_DATA_LENGTH 32
 
+/* Apple SMC status bits */
+#define SMC_STATUS_AWAITING_DATA  BIT(0) /* SMC has data waiting */
+#define SMC_STATUS_IB_CLOSED      BIT(1) /* Will ignore any input */
+#define SMC_STATUS_BUSY           BIT(2) /* Command in progress */
+
 /* wait up to 128 ms for a status change. */
 #define APPLESMC_MIN_WAIT	0x0010
 #define APPLESMC_RETRY_WAIT	0x0100
@@ -151,65 +157,78 @@ static unsigned int key_at_index;
 static struct workqueue_struct *applesmc_led_wq;
 
 /*
- * wait_read - Wait for a byte to appear on SMC port. Callers must
- * hold applesmc_lock.
+ * Wait for specific status bits with a mask on the SMC
+ * Used before and after writes, and before reads
+ * On success, returns the full status
+ * On failure, returns a negative error
  */
-static int wait_read(void)
+
+static int wait_status(u8 val, u8 mask)
 {
 	unsigned long end = jiffies + (APPLESMC_MAX_WAIT * HZ) / USEC_PER_SEC;
 	u8 status;
 	int us;
 
 	for (us = APPLESMC_MIN_WAIT; us < APPLESMC_MAX_WAIT; us <<= 1) {
-		usleep_range(us, us * 16);
 		status = inb(APPLESMC_CMD_PORT);
-		/* read: wait for smc to settle */
-		if (status & 0x01)
-			return 0;
+		if ((status & mask) == val)
+			return status;
 		/* timeout: give up */
 		if (time_after(jiffies, end))
 			break;
+		usleep_range(us, us * 16);
 	}
-
-	pr_warn("wait_read() fail: 0x%02x\n", status);
 	return -EIO;
 }
 
 /*
- * send_byte - Write to SMC port, retrying when necessary. Callers
+ * send_byte_data - Write to SMC data port. Callers
  * must hold applesmc_lock.
+ * Parameter skip must be true on the last write of any
+ * command or it'll time out.
  */
-static int send_byte(u8 cmd, u16 port)
+
+static int send_byte_data(u8 cmd, u16 port, bool skip)
 {
-	u8 status;
-	int us;
-	unsigned long end = jiffies + (APPLESMC_MAX_WAIT * HZ) / USEC_PER_SEC;
+	int status;
 
+	status = wait_status(0, SMC_STATUS_IB_CLOSED);
+	if (status < 0)
+		return status;
 	outb(cmd, port);
-	for (us = APPLESMC_MIN_WAIT; us < APPLESMC_MAX_WAIT; us <<= 1) {
-		usleep_range(us, us * 16);
-		status = inb(APPLESMC_CMD_PORT);
-		/* write: wait for smc to settle */
-		if (status & 0x02)
-			continue;
-		/* ready: cmd accepted, return */
-		if (status & 0x04)
-			return 0;
-		/* timeout: give up */
-		if (time_after(jiffies, end))
-			break;
-		/* busy: long wait and resend */
-		udelay(APPLESMC_RETRY_WAIT);
-		outb(cmd, port);
-	}
+	udelay(APPLESMC_MIN_WAIT);
+	status = wait_status(0, SMC_STATUS_IB_CLOSED);
+	if (status < 0)
+		return status;
+	if (skip || (status & SMC_STATUS_BUSY))
+		return 0;
+	return -EAGAIN;
+}
 
-	pr_warn("send_byte(0x%02x, 0x%04x) fail: 0x%02x\n", cmd, port, status);
-	return -EIO;
+static int send_byte(u8 cmd, u16 port)
+{
+	return send_byte_data(cmd, port, false);
 }
 
+/*
+ * send_command - Write a command to the SMC. Callers must hold applesmc_lock.
+ * If SMC is in undefined state, any new command write resets the state machine.
+ */
+
 static int send_command(u8 cmd)
 {
-	return send_byte(cmd, APPLESMC_CMD_PORT);
+	int ret;
+	int i;
+
+	for (i = 0; i < 16; i++) {
+		ret = send_byte(cmd, APPLESMC_CMD_PORT);
+		if (!ret)
+			return ret;
+		if (ret != -EAGAIN)
+			break;
+		usleep_range(APPLESMC_MIN_WAIT, APPLESMC_MIN_WAIT * 16);
+	}
+	return -EIO;
 }
 
 static int send_argument(const char *key)
@@ -239,7 +258,8 @@ static int read_smc(u8 cmd, const char *key, u8 *buffer, u8 len)
 	}
 
 	for (i = 0; i < len; i++) {
-		if (wait_read()) {
+		if (wait_status(SMC_STATUS_AWAITING_DATA,
+					SMC_STATUS_AWAITING_DATA | SMC_STATUS_IB_CLOSED) < 0) {
 			pr_warn("%.4s: read data[%d] fail\n", key, i);
 			return -EIO;
 		}
@@ -250,7 +270,7 @@ static int read_smc(u8 cmd, const char *key, u8 *buffer, u8 len)
 	for (i = 0; i < 16; i++) {
 		udelay(APPLESMC_MIN_WAIT);
 		status = inb(APPLESMC_CMD_PORT);
-		if (!(status & 0x01))
+		if (!(status & SMC_STATUS_AWAITING_DATA))
 			break;
 		data = inb(APPLESMC_DATA_PORT);
 	}
@@ -275,7 +295,7 @@ static int write_smc(u8 cmd, const char *key, const u8 *buffer, u8 len)
 	}
 
 	for (i = 0; i < len; i++) {
-		if (send_byte(buffer[i], APPLESMC_DATA_PORT)) {
+		if (send_byte_data(buffer[i], APPLESMC_DATA_PORT, i == len - 1)) {
 			pr_warn("%s: write data fail\n", key);
 			return -EIO;
 		}

Brad Campbell Nov. 8, 2020, 11:57 a.m. UTC | #3

On 8/11/20 9:14 pm, Henrik Rydberg wrote:
> On Sun, Nov 08, 2020 at 09:35:28AM +0100, Henrik Rydberg wrote:
>> Hi Brad,
>>
>> On 2020-11-08 02:00, Brad Campbell wrote:
>>> G'day Henrik,
>>>
>>> I noticed you'd also loosened up the requirement for SMC_STATUS_BUSY in read_smc(). I assume
>>> that causes problems on the early Macbook. This is revised on the one sent earlier.
>>> If you could test this on your Air1,1 it'd be appreciated.
>>
>> No, I managed to screw up the patch; you can see that I carefully added the
>> same treatment for the read argument, being unsure if the BUSY state would
>> remain during the AVAILABLE data phase. I can check that again, but
>> unfortunately the patch in this email shows the same problem.
>>
>> I think it may be worthwhile to rethink the behavior of wait_status() here.
>> If one machine shows no change after a certain status bit change, then
>> perhaps the others share that behavior, and we are waiting in vain. Just
>> imagine how many years of cpu that is, combined. ;-)
> 
> Here is a modification along that line.
> 
> Compared to your latest version, this one has wait_status() return the
> actual status on success. Instead of waiting for BUSY, it waits for
> the other status bits, and checks BUSY afterwards. So as not to wait
> unneccesarily, the udelay() is placed together with the single
> outb(). The return value of send_byte_data() is augmented with
> -EAGAIN, which is then used in send_command() to create the resend
> loop.
> 
> I reach 41 reads per second on the MBA1,1 with this version, which is
> getting close to the performance prior to the problems.

G'day Henrik,

I like this one. It's slower on my laptop (40 rps vs 50 on the MacbookPro11,1) and the same 17 rps on the iMac 12,2 but it's as reliable
and if it works for both of yours then I think it's a winner. I can't really diagnose the iMac properly as I'm 2,800KM away and have
nobody to reboot it if I kill it. 5.7.2 gives 20 rps, so 17 is ok for me.

Andreas, could I ask you to test this one?

Odd my original version worked on your Air3,1 and the other 3 machines without retry.
I wonder how many commands require retries, how many retires are actually required, and what we are going wrong on the Air1,1 that requires
one or more retries. 

I just feels like a brute force approach because there's something we're missing.

> From b4405457f4ba07cff7b7e4f48c47668bee176a25 Mon Sep 17 00:00:00 2001
> From: Brad Campbell <[e-mail]>
> Date: Sun, 8 Nov 2020 12:00:03 +1100
> Subject: [PATCH] hwmon: (applesmc) Re-work SMC comms
> 
> Commit fff2d0f701e6 ("hwmon: (applesmc) avoid overlong udelay()")
> introduced an issue whereby communication with the SMC became
> unreliable with write errors like :
> 
> [  120.378614] applesmc: send_byte(0x00, 0x0300) fail: 0x40
> [  120.378621] applesmc: LKSB: write data fail
> [  120.512782] applesmc: send_byte(0x00, 0x0300) fail: 0x40
> [  120.512787] applesmc: LKSB: write data fail
> 
> The original code appeared to be timing sensitive and was not reliable
> with the timing changes in the aforementioned commit.
> 
> This patch re-factors the SMC communication to remove the timing
> dependencies and restore function with the changes previously
> committed.
> 
> Tested on : MacbookAir6,2 MacBookPro11,1 iMac12,2, MacBookAir1,1,
> MacBookAir3,1
> 
> Fixes: fff2d0f701e6 ("hwmon: (applesmc) avoid overlong udelay()")
> Reported-by: Andreas Kemnade <[e-mail]>
> Tested-by: Andreas Kemnade <[e-mail]> # MacBookAir6,2
> Acked-by: Arnd Bergmann <[e-mail]>
> Signed-off-by: Brad Campbell <[e-mail]>
> Signed-off-by: Henrik Rydberg <[e-mail]>
> 
> ---
> Changelog : 
> v1 : Inital attempt
> v2 : Address logic and coding style
> v3 : Removed some debug hangover. Added tested-by. Modifications for MacBookAir1,1
> v4 : Do not expect busy state to appear without other state changes
> 
> diff --git a/drivers/hwmon/applesmc.c b/drivers/hwmon/applesmc.c
> index a18887990f4a..ea7c66d5788e 100644
> --- a/drivers/hwmon/applesmc.c
> +++ b/drivers/hwmon/applesmc.c
> @@ -32,6 +32,7 @@
>  #include <linux/hwmon.h>
>  #include <linux/workqueue.h>
>  #include <linux/err.h>
> +#include <linux/bits.h>
>  
>  /* data port used by Apple SMC */
>  #define APPLESMC_DATA_PORT	0x300
> @@ -42,6 +43,11 @@
>  
>  #define APPLESMC_MAX_DATA_LENGTH 32
>  
> +/* Apple SMC status bits */
> +#define SMC_STATUS_AWAITING_DATA  BIT(0) /* SMC has data waiting */
> +#define SMC_STATUS_IB_CLOSED      BIT(1) /* Will ignore any input */
> +#define SMC_STATUS_BUSY           BIT(2) /* Command in progress */
> +
>  /* wait up to 128 ms for a status change. */
>  #define APPLESMC_MIN_WAIT	0x0010
>  #define APPLESMC_RETRY_WAIT	0x0100
> @@ -151,65 +157,78 @@ static unsigned int key_at_index;
>  static struct workqueue_struct *applesmc_led_wq;
>  
>  /*
> - * wait_read - Wait for a byte to appear on SMC port. Callers must
> - * hold applesmc_lock.
> + * Wait for specific status bits with a mask on the SMC
> + * Used before and after writes, and before reads
> + * On success, returns the full status
> + * On failure, returns a negative error
>   */
> -static int wait_read(void)
> +
> +static int wait_status(u8 val, u8 mask)
>  {
>  	unsigned long end = jiffies + (APPLESMC_MAX_WAIT * HZ) / USEC_PER_SEC;
>  	u8 status;
>  	int us;
>  
>  	for (us = APPLESMC_MIN_WAIT; us < APPLESMC_MAX_WAIT; us <<= 1) {
> -		usleep_range(us, us * 16);
>  		status = inb(APPLESMC_CMD_PORT);
> -		/* read: wait for smc to settle */
> -		if (status & 0x01)
> -			return 0;
> +		if ((status & mask) == val)
> +			return status;
>  		/* timeout: give up */
>  		if (time_after(jiffies, end))
>  			break;
> +		usleep_range(us, us * 16);
>  	}
> -
> -	pr_warn("wait_read() fail: 0x%02x\n", status);
>  	return -EIO;
>  }
>  
>  /*
> - * send_byte - Write to SMC port, retrying when necessary. Callers
> + * send_byte_data - Write to SMC data port. Callers
>   * must hold applesmc_lock.
> + * Parameter skip must be true on the last write of any
> + * command or it'll time out.
>   */
> -static int send_byte(u8 cmd, u16 port)
> +
> +static int send_byte_data(u8 cmd, u16 port, bool skip)
>  {
> -	u8 status;
> -	int us;
> -	unsigned long end = jiffies + (APPLESMC_MAX_WAIT * HZ) / USEC_PER_SEC;
> +	int status;
>  
> +	status = wait_status(0, SMC_STATUS_IB_CLOSED);
> +	if (status < 0)
> +		return status;
>  	outb(cmd, port);
> -	for (us = APPLESMC_MIN_WAIT; us < APPLESMC_MAX_WAIT; us <<= 1) {
> -		usleep_range(us, us * 16);
> -		status = inb(APPLESMC_CMD_PORT);
> -		/* write: wait for smc to settle */
> -		if (status & 0x02)
> -			continue;
> -		/* ready: cmd accepted, return */
> -		if (status & 0x04)
> -			return 0;
> -		/* timeout: give up */
> -		if (time_after(jiffies, end))
> -			break;
> -		/* busy: long wait and resend */
> -		udelay(APPLESMC_RETRY_WAIT);
> -		outb(cmd, port);
> -	}
> +	udelay(APPLESMC_MIN_WAIT);
> +	status = wait_status(0, SMC_STATUS_IB_CLOSED);
> +	if (status < 0)
> +		return status;
> +	if (skip || (status & SMC_STATUS_BUSY))
> +		return 0;
> +	return -EAGAIN;
> +}
>  
> -	pr_warn("send_byte(0x%02x, 0x%04x) fail: 0x%02x\n", cmd, port, status);
> -	return -EIO;
> +static int send_byte(u8 cmd, u16 port)
> +{
> +	return send_byte_data(cmd, port, false);
>  }
>  
> +/*
> + * send_command - Write a command to the SMC. Callers must hold applesmc_lock.
> + * If SMC is in undefined state, any new command write resets the state machine.
> + */
> +
>  static int send_command(u8 cmd)
>  {
> -	return send_byte(cmd, APPLESMC_CMD_PORT);
> +	int ret;
> +	int i;
> +
> +	for (i = 0; i < 16; i++) {
> +		ret = send_byte(cmd, APPLESMC_CMD_PORT);
> +		if (!ret)
> +			return ret;
> +		if (ret != -EAGAIN)
> +			break;
> +		usleep_range(APPLESMC_MIN_WAIT, APPLESMC_MIN_WAIT * 16);
> +	}
> +	return -EIO;
>  }
>  
>  static int send_argument(const char *key)
> @@ -239,7 +258,8 @@ static int read_smc(u8 cmd, const char *key, u8 *buffer, u8 len)
>  	}
>  
>  	for (i = 0; i < len; i++) {
> -		if (wait_read()) {
> +		if (wait_status(SMC_STATUS_AWAITING_DATA,
> +					SMC_STATUS_AWAITING_DATA | SMC_STATUS_IB_CLOSED) < 0) {
>  			pr_warn("%.4s: read data[%d] fail\n", key, i);
>  			return -EIO;
>  		}
> @@ -250,7 +270,7 @@ static int read_smc(u8 cmd, const char *key, u8 *buffer, u8 len)
>  	for (i = 0; i < 16; i++) {
>  		udelay(APPLESMC_MIN_WAIT);
>  		status = inb(APPLESMC_CMD_PORT);
> -		if (!(status & 0x01))
> +		if (!(status & SMC_STATUS_AWAITING_DATA))
>  			break;
>  		data = inb(APPLESMC_DATA_PORT);
>  	}
> @@ -275,7 +295,7 @@ static int write_smc(u8 cmd, const char *key, const u8 *buffer, u8 len)
>  	}
>  
>  	for (i = 0; i < len; i++) {
> -		if (send_byte(buffer[i], APPLESMC_DATA_PORT)) {
> +		if (send_byte_data(buffer[i], APPLESMC_DATA_PORT, i == len - 1)) {
>  			pr_warn("%s: write data fail\n", key);
>  			return -EIO;
>  		}
>

Henrik Rydberg Nov. 8, 2020, 12:04 p.m. UTC | #4

On 2020-11-08 12:57, Brad Campbell wrote:
> On 8/11/20 9:14 pm, Henrik Rydberg wrote:
>> On Sun, Nov 08, 2020 at 09:35:28AM +0100, Henrik Rydberg wrote:
>>> Hi Brad,
>>>
>>> On 2020-11-08 02:00, Brad Campbell wrote:
>>>> G'day Henrik,
>>>>
>>>> I noticed you'd also loosened up the requirement for SMC_STATUS_BUSY in read_smc(). I assume
>>>> that causes problems on the early Macbook. This is revised on the one sent earlier.
>>>> If you could test this on your Air1,1 it'd be appreciated.
>>>
>>> No, I managed to screw up the patch; you can see that I carefully added the
>>> same treatment for the read argument, being unsure if the BUSY state would
>>> remain during the AVAILABLE data phase. I can check that again, but
>>> unfortunately the patch in this email shows the same problem.
>>>
>>> I think it may be worthwhile to rethink the behavior of wait_status() here.
>>> If one machine shows no change after a certain status bit change, then
>>> perhaps the others share that behavior, and we are waiting in vain. Just
>>> imagine how many years of cpu that is, combined. ;-)
>>
>> Here is a modification along that line.
>>
>> Compared to your latest version, this one has wait_status() return the
>> actual status on success. Instead of waiting for BUSY, it waits for
>> the other status bits, and checks BUSY afterwards. So as not to wait
>> unneccesarily, the udelay() is placed together with the single
>> outb(). The return value of send_byte_data() is augmented with
>> -EAGAIN, which is then used in send_command() to create the resend
>> loop.
>>
>> I reach 41 reads per second on the MBA1,1 with this version, which is
>> getting close to the performance prior to the problems.
> 
> G'day Henrik,
> 
> I like this one. It's slower on my laptop (40 rps vs 50 on the MacbookPro11,1) and the same 17 rps on the iMac 12,2 but it's as reliable
> and if it works for both of yours then I think it's a winner. I can't really diagnose the iMac properly as I'm 2,800KM away and have
> nobody to reboot it if I kill it. 5.7.2 gives 20 rps, so 17 is ok for me.
> 
> Andreas, could I ask you to test this one?
> 
> Odd my original version worked on your Air3,1 and the other 3 machines without retry.
> I wonder how many commands require retries, how many retires are actually required, and what we are going wrong on the Air1,1 that requires
> one or more retries.
> 
> I just feels like a brute force approach because there's something we're missing.

I would think you are right. There should be a way to follow the status 
changes in realtime, so one can determine handshake and processing from 
that information. At least, with this change, we are making the blunt 
instrument a little smaller.

Cheers,
Henrik

Guenter Roeck Nov. 8, 2020, 4:06 p.m. UTC | #5

On 11/8/20 2:14 AM, Henrik Rydberg wrote:
> On Sun, Nov 08, 2020 at 09:35:28AM +0100, Henrik Rydberg wrote:
>> Hi Brad,
>>
>> On 2020-11-08 02:00, Brad Campbell wrote:
>>> G'day Henrik,
>>>
>>> I noticed you'd also loosened up the requirement for SMC_STATUS_BUSY in read_smc(). I assume
>>> that causes problems on the early Macbook. This is revised on the one sent earlier.
>>> If you could test this on your Air1,1 it'd be appreciated.
>>
>> No, I managed to screw up the patch; you can see that I carefully added the
>> same treatment for the read argument, being unsure if the BUSY state would
>> remain during the AVAILABLE data phase. I can check that again, but
>> unfortunately the patch in this email shows the same problem.
>>
>> I think it may be worthwhile to rethink the behavior of wait_status() here.
>> If one machine shows no change after a certain status bit change, then
>> perhaps the others share that behavior, and we are waiting in vain. Just
>> imagine how many years of cpu that is, combined. ;-)
> 
> Here is a modification along that line.
> 

Please resend this patch as stand-alone v4 patch. If sent like it was sent here,
it doesn't make it into patchwork, and is thus not only difficult to apply but
may get lost, and it is all but impossible to find and apply all tags.
Also, prior to Henrik's Signed=off-by: there should be a one-line explanation
of the changes made.

Thanks,
Guenter

> Compared to your latest version, this one has wait_status() return the
> actual status on success. Instead of waiting for BUSY, it waits for
> the other status bits, and checks BUSY afterwards. So as not to wait
> unneccesarily, the udelay() is placed together with the single
> outb(). The return value of send_byte_data() is augmented with
> -EAGAIN, which is then used in send_command() to create the resend
> loop.
> 
> I reach 41 reads per second on the MBA1,1 with this version, which is
> getting close to the performance prior to the problems.
> 
>>From b4405457f4ba07cff7b7e4f48c47668bee176a25 Mon Sep 17 00:00:00 2001
> From: Brad Campbell <[e-mail]>
> Date: Sun, 8 Nov 2020 12:00:03 +1100
> Subject: [PATCH] hwmon: (applesmc) Re-work SMC comms
> 
> Commit fff2d0f701e6 ("hwmon: (applesmc) avoid overlong udelay()")
> introduced an issue whereby communication with the SMC became
> unreliable with write errors like :
> 
> [  120.378614] applesmc: send_byte(0x00, 0x0300) fail: 0x40
> [  120.378621] applesmc: LKSB: write data fail
> [  120.512782] applesmc: send_byte(0x00, 0x0300) fail: 0x40
> [  120.512787] applesmc: LKSB: write data fail
> 
> The original code appeared to be timing sensitive and was not reliable
> with the timing changes in the aforementioned commit.
> 
> This patch re-factors the SMC communication to remove the timing
> dependencies and restore function with the changes previously
> committed.
> 
> Tested on : MacbookAir6,2 MacBookPro11,1 iMac12,2, MacBookAir1,1,
> MacBookAir3,1
> 
> Fixes: fff2d0f701e6 ("hwmon: (applesmc) avoid overlong udelay()")
> Reported-by: Andreas Kemnade <[e-mail]>
> Tested-by: Andreas Kemnade <[e-mail]> # MacBookAir6,2
> Acked-by: Arnd Bergmann <[e-mail]>
> Signed-off-by: Brad Campbell <[e-mail]>
> Signed-off-by: Henrik Rydberg <[e-mail]>
> 
> ---
> Changelog : 
> v1 : Inital attempt
> v2 : Address logic and coding style
> v3 : Removed some debug hangover. Added tested-by. Modifications for MacBookAir1,1
> v4 : Do not expect busy state to appear without other state changes
> 
> diff --git a/drivers/hwmon/applesmc.c b/drivers/hwmon/applesmc.c
> index a18887990f4a..ea7c66d5788e 100644
> --- a/drivers/hwmon/applesmc.c
> +++ b/drivers/hwmon/applesmc.c
> @@ -32,6 +32,7 @@
>  #include <linux/hwmon.h>
>  #include <linux/workqueue.h>
>  #include <linux/err.h>
> +#include <linux/bits.h>
>  
>  /* data port used by Apple SMC */
>  #define APPLESMC_DATA_PORT	0x300
> @@ -42,6 +43,11 @@
>  
>  #define APPLESMC_MAX_DATA_LENGTH 32
>  
> +/* Apple SMC status bits */
> +#define SMC_STATUS_AWAITING_DATA  BIT(0) /* SMC has data waiting */
> +#define SMC_STATUS_IB_CLOSED      BIT(1) /* Will ignore any input */
> +#define SMC_STATUS_BUSY           BIT(2) /* Command in progress */
> +
>  /* wait up to 128 ms for a status change. */
>  #define APPLESMC_MIN_WAIT	0x0010
>  #define APPLESMC_RETRY_WAIT	0x0100
> @@ -151,65 +157,78 @@ static unsigned int key_at_index;
>  static struct workqueue_struct *applesmc_led_wq;
>  
>  /*
> - * wait_read - Wait for a byte to appear on SMC port. Callers must
> - * hold applesmc_lock.
> + * Wait for specific status bits with a mask on the SMC
> + * Used before and after writes, and before reads
> + * On success, returns the full status
> + * On failure, returns a negative error
>   */
> -static int wait_read(void)
> +
> +static int wait_status(u8 val, u8 mask)
>  {
>  	unsigned long end = jiffies + (APPLESMC_MAX_WAIT * HZ) / USEC_PER_SEC;
>  	u8 status;
>  	int us;
>  
>  	for (us = APPLESMC_MIN_WAIT; us < APPLESMC_MAX_WAIT; us <<= 1) {
> -		usleep_range(us, us * 16);
>  		status = inb(APPLESMC_CMD_PORT);
> -		/* read: wait for smc to settle */
> -		if (status & 0x01)
> -			return 0;
> +		if ((status & mask) == val)
> +			return status;
>  		/* timeout: give up */
>  		if (time_after(jiffies, end))
>  			break;
> +		usleep_range(us, us * 16);
>  	}
> -
> -	pr_warn("wait_read() fail: 0x%02x\n", status);
>  	return -EIO;
>  }
>  
>  /*
> - * send_byte - Write to SMC port, retrying when necessary. Callers
> + * send_byte_data - Write to SMC data port. Callers
>   * must hold applesmc_lock.
> + * Parameter skip must be true on the last write of any
> + * command or it'll time out.
>   */
> -static int send_byte(u8 cmd, u16 port)
> +
> +static int send_byte_data(u8 cmd, u16 port, bool skip)
>  {
> -	u8 status;
> -	int us;
> -	unsigned long end = jiffies + (APPLESMC_MAX_WAIT * HZ) / USEC_PER_SEC;
> +	int status;
>  
> +	status = wait_status(0, SMC_STATUS_IB_CLOSED);
> +	if (status < 0)
> +		return status;
>  	outb(cmd, port);
> -	for (us = APPLESMC_MIN_WAIT; us < APPLESMC_MAX_WAIT; us <<= 1) {
> -		usleep_range(us, us * 16);
> -		status = inb(APPLESMC_CMD_PORT);
> -		/* write: wait for smc to settle */
> -		if (status & 0x02)
> -			continue;
> -		/* ready: cmd accepted, return */
> -		if (status & 0x04)
> -			return 0;
> -		/* timeout: give up */
> -		if (time_after(jiffies, end))
> -			break;
> -		/* busy: long wait and resend */
> -		udelay(APPLESMC_RETRY_WAIT);
> -		outb(cmd, port);
> -	}
> +	udelay(APPLESMC_MIN_WAIT);
> +	status = wait_status(0, SMC_STATUS_IB_CLOSED);
> +	if (status < 0)
> +		return status;
> +	if (skip || (status & SMC_STATUS_BUSY))
> +		return 0;
> +	return -EAGAIN;
> +}
>  
> -	pr_warn("send_byte(0x%02x, 0x%04x) fail: 0x%02x\n", cmd, port, status);
> -	return -EIO;
> +static int send_byte(u8 cmd, u16 port)
> +{
> +	return send_byte_data(cmd, port, false);
>  }
>  
> +/*
> + * send_command - Write a command to the SMC. Callers must hold applesmc_lock.
> + * If SMC is in undefined state, any new command write resets the state machine.
> + */
> +
>  static int send_command(u8 cmd)
>  {
> -	return send_byte(cmd, APPLESMC_CMD_PORT);
> +	int ret;
> +	int i;
> +
> +	for (i = 0; i < 16; i++) {
> +		ret = send_byte(cmd, APPLESMC_CMD_PORT);
> +		if (!ret)
> +			return ret;
> +		if (ret != -EAGAIN)
> +			break;
> +		usleep_range(APPLESMC_MIN_WAIT, APPLESMC_MIN_WAIT * 16);
> +	}
> +	return -EIO;
>  }
>  
>  static int send_argument(const char *key)
> @@ -239,7 +258,8 @@ static int read_smc(u8 cmd, const char *key, u8 *buffer, u8 len)
>  	}
>  
>  	for (i = 0; i < len; i++) {
> -		if (wait_read()) {
> +		if (wait_status(SMC_STATUS_AWAITING_DATA,
> +					SMC_STATUS_AWAITING_DATA | SMC_STATUS_IB_CLOSED) < 0) {
>  			pr_warn("%.4s: read data[%d] fail\n", key, i);
>  			return -EIO;
>  		}
> @@ -250,7 +270,7 @@ static int read_smc(u8 cmd, const char *key, u8 *buffer, u8 len)
>  	for (i = 0; i < 16; i++) {
>  		udelay(APPLESMC_MIN_WAIT);
>  		status = inb(APPLESMC_CMD_PORT);
> -		if (!(status & 0x01))
> +		if (!(status & SMC_STATUS_AWAITING_DATA))
>  			break;
>  		data = inb(APPLESMC_DATA_PORT);
>  	}
> @@ -275,7 +295,7 @@ static int write_smc(u8 cmd, const char *key, const u8 *buffer, u8 len)
>  	}
>  
>  	for (i = 0; i < len; i++) {
> -		if (send_byte(buffer[i], APPLESMC_DATA_PORT)) {
> +		if (send_byte_data(buffer[i], APPLESMC_DATA_PORT, i == len - 1)) {
>  			pr_warn("%s: write data fail\n", key);
>  			return -EIO;
>  		}
>

Brad Campbell Nov. 9, 2020, 12:25 a.m. UTC | #6

On 9/11/20 3:06 am, Guenter Roeck wrote:
> On 11/8/20 2:14 AM, Henrik Rydberg wrote:
>> On Sun, Nov 08, 2020 at 09:35:28AM +0100, Henrik Rydberg wrote:
>>> Hi Brad,
>>>
>>> On 2020-11-08 02:00, Brad Campbell wrote:
>>>> G'day Henrik,
>>>>
>>>> I noticed you'd also loosened up the requirement for SMC_STATUS_BUSY in read_smc(). I assume
>>>> that causes problems on the early Macbook. This is revised on the one sent earlier.
>>>> If you could test this on your Air1,1 it'd be appreciated.
>>>
>>> No, I managed to screw up the patch; you can see that I carefully added the
>>> same treatment for the read argument, being unsure if the BUSY state would
>>> remain during the AVAILABLE data phase. I can check that again, but
>>> unfortunately the patch in this email shows the same problem.
>>>
>>> I think it may be worthwhile to rethink the behavior of wait_status() here.
>>> If one machine shows no change after a certain status bit change, then
>>> perhaps the others share that behavior, and we are waiting in vain. Just
>>> imagine how many years of cpu that is, combined. ;-)
>>
>> Here is a modification along that line.
>>
> 
> Please resend this patch as stand-alone v4 patch. If sent like it was sent here,
> it doesn't make it into patchwork, and is thus not only difficult to apply but
> may get lost, and it is all but impossible to find and apply all tags.
> Also, prior to Henrik's Signed=off-by: there should be a one-line explanation
> of the changes made.

G'day Guenter,

Yes, I'll do that. I still have some more testing to do before it's pushed forwards.

Regards,
Brad
> 
>> Compared to your latest version, this one has wait_status() return the
>> actual status on success. Instead of waiting for BUSY, it waits for
>> the other status bits, and checks BUSY afterwards. So as not to wait
>> unneccesarily, the udelay() is placed together with the single
>> outb(). The return value of send_byte_data() is augmented with
>> -EAGAIN, which is then used in send_command() to create the resend
>> loop.
>>
>> I reach 41 reads per second on the MBA1,1 with this version, which is
>> getting close to the performance prior to the problems.
>>
>> >From b4405457f4ba07cff7b7e4f48c47668bee176a25 Mon Sep 17 00:00:00 2001
>> From: Brad Campbell <[e-mail]>
>> Date: Sun, 8 Nov 2020 12:00:03 +1100
>> Subject: [PATCH] hwmon: (applesmc) Re-work SMC comms
>>
>> Commit fff2d0f701e6 ("hwmon: (applesmc) avoid overlong udelay()")
>> introduced an issue whereby communication with the SMC became
>> unreliable with write errors like :
>>
>> [  120.378614] applesmc: send_byte(0x00, 0x0300) fail: 0x40
>> [  120.378621] applesmc: LKSB: write data fail
>> [  120.512782] applesmc: send_byte(0x00, 0x0300) fail: 0x40
>> [  120.512787] applesmc: LKSB: write data fail
>>
>> The original code appeared to be timing sensitive and was not reliable
>> with the timing changes in the aforementioned commit.
>>
>> This patch re-factors the SMC communication to remove the timing
>> dependencies and restore function with the changes previously
>> committed.
>>
>> Tested on : MacbookAir6,2 MacBookPro11,1 iMac12,2, MacBookAir1,1,
>> MacBookAir3,1
>>
>> Fixes: fff2d0f701e6 ("hwmon: (applesmc) avoid overlong udelay()")
>> Reported-by: Andreas Kemnade <[e-mail]>
>> Tested-by: Andreas Kemnade <[e-mail]> # MacBookAir6,2
>> Acked-by: Arnd Bergmann <[e-mail]>
>> Signed-off-by: Brad Campbell <[e-mail]>
>> Signed-off-by: Henrik Rydberg <[e-mail]>
>>
>> ---
>> Changelog : 
>> v1 : Inital attempt
>> v2 : Address logic and coding style
>> v3 : Removed some debug hangover. Added tested-by. Modifications for MacBookAir1,1
>> v4 : Do not expect busy state to appear without other state changes
>>
>> diff --git a/drivers/hwmon/applesmc.c b/drivers/hwmon/applesmc.c
>> index a18887990f4a..ea7c66d5788e 100644
>> --- a/drivers/hwmon/applesmc.c
>> +++ b/drivers/hwmon/applesmc.c
>> @@ -32,6 +32,7 @@
>>  #include <linux/hwmon.h>
>>  #include <linux/workqueue.h>
>>  #include <linux/err.h>
>> +#include <linux/bits.h>
>>  
>>  /* data port used by Apple SMC */
>>  #define APPLESMC_DATA_PORT	0x300
>> @@ -42,6 +43,11 @@
>>  
>>  #define APPLESMC_MAX_DATA_LENGTH 32
>>  
>> +/* Apple SMC status bits */
>> +#define SMC_STATUS_AWAITING_DATA  BIT(0) /* SMC has data waiting */
>> +#define SMC_STATUS_IB_CLOSED      BIT(1) /* Will ignore any input */
>> +#define SMC_STATUS_BUSY           BIT(2) /* Command in progress */
>> +
>>  /* wait up to 128 ms for a status change. */
>>  #define APPLESMC_MIN_WAIT	0x0010
>>  #define APPLESMC_RETRY_WAIT	0x0100
>> @@ -151,65 +157,78 @@ static unsigned int key_at_index;
>>  static struct workqueue_struct *applesmc_led_wq;
>>  
>>  /*
>> - * wait_read - Wait for a byte to appear on SMC port. Callers must
>> - * hold applesmc_lock.
>> + * Wait for specific status bits with a mask on the SMC
>> + * Used before and after writes, and before reads
>> + * On success, returns the full status
>> + * On failure, returns a negative error
>>   */
>> -static int wait_read(void)
>> +
>> +static int wait_status(u8 val, u8 mask)
>>  {
>>  	unsigned long end = jiffies + (APPLESMC_MAX_WAIT * HZ) / USEC_PER_SEC;
>>  	u8 status;
>>  	int us;
>>  
>>  	for (us = APPLESMC_MIN_WAIT; us < APPLESMC_MAX_WAIT; us <<= 1) {
>> -		usleep_range(us, us * 16);
>>  		status = inb(APPLESMC_CMD_PORT);
>> -		/* read: wait for smc to settle */
>> -		if (status & 0x01)
>> -			return 0;
>> +		if ((status & mask) == val)
>> +			return status;
>>  		/* timeout: give up */
>>  		if (time_after(jiffies, end))
>>  			break;
>> +		usleep_range(us, us * 16);
>>  	}
>> -
>> -	pr_warn("wait_read() fail: 0x%02x\n", status);
>>  	return -EIO;
>>  }
>>  
>>  /*
>> - * send_byte - Write to SMC port, retrying when necessary. Callers
>> + * send_byte_data - Write to SMC data port. Callers
>>   * must hold applesmc_lock.
>> + * Parameter skip must be true on the last write of any
>> + * command or it'll time out.
>>   */
>> -static int send_byte(u8 cmd, u16 port)
>> +
>> +static int send_byte_data(u8 cmd, u16 port, bool skip)
>>  {
>> -	u8 status;
>> -	int us;
>> -	unsigned long end = jiffies + (APPLESMC_MAX_WAIT * HZ) / USEC_PER_SEC;
>> +	int status;
>>  
>> +	status = wait_status(0, SMC_STATUS_IB_CLOSED);
>> +	if (status < 0)
>> +		return status;
>>  	outb(cmd, port);
>> -	for (us = APPLESMC_MIN_WAIT; us < APPLESMC_MAX_WAIT; us <<= 1) {
>> -		usleep_range(us, us * 16);
>> -		status = inb(APPLESMC_CMD_PORT);
>> -		/* write: wait for smc to settle */
>> -		if (status & 0x02)
>> -			continue;
>> -		/* ready: cmd accepted, return */
>> -		if (status & 0x04)
>> -			return 0;
>> -		/* timeout: give up */
>> -		if (time_after(jiffies, end))
>> -			break;
>> -		/* busy: long wait and resend */
>> -		udelay(APPLESMC_RETRY_WAIT);
>> -		outb(cmd, port);
>> -	}
>> +	udelay(APPLESMC_MIN_WAIT);
>> +	status = wait_status(0, SMC_STATUS_IB_CLOSED);
>> +	if (status < 0)
>> +		return status;
>> +	if (skip || (status & SMC_STATUS_BUSY))
>> +		return 0;
>> +	return -EAGAIN;
>> +}
>>  
>> -	pr_warn("send_byte(0x%02x, 0x%04x) fail: 0x%02x\n", cmd, port, status);
>> -	return -EIO;
>> +static int send_byte(u8 cmd, u16 port)
>> +{
>> +	return send_byte_data(cmd, port, false);
>>  }
>>  
>> +/*
>> + * send_command - Write a command to the SMC. Callers must hold applesmc_lock.
>> + * If SMC is in undefined state, any new command write resets the state machine.
>> + */
>> +
>>  static int send_command(u8 cmd)
>>  {
>> -	return send_byte(cmd, APPLESMC_CMD_PORT);
>> +	int ret;
>> +	int i;
>> +
>> +	for (i = 0; i < 16; i++) {
>> +		ret = send_byte(cmd, APPLESMC_CMD_PORT);
>> +		if (!ret)
>> +			return ret;
>> +		if (ret != -EAGAIN)
>> +			break;
>> +		usleep_range(APPLESMC_MIN_WAIT, APPLESMC_MIN_WAIT * 16);
>> +	}
>> +	return -EIO;
>>  }
>>  
>>  static int send_argument(const char *key)
>> @@ -239,7 +258,8 @@ static int read_smc(u8 cmd, const char *key, u8 *buffer, u8 len)
>>  	}
>>  
>>  	for (i = 0; i < len; i++) {
>> -		if (wait_read()) {
>> +		if (wait_status(SMC_STATUS_AWAITING_DATA,
>> +					SMC_STATUS_AWAITING_DATA | SMC_STATUS_IB_CLOSED) < 0) {
>>  			pr_warn("%.4s: read data[%d] fail\n", key, i);
>>  			return -EIO;
>>  		}
>> @@ -250,7 +270,7 @@ static int read_smc(u8 cmd, const char *key, u8 *buffer, u8 len)
>>  	for (i = 0; i < 16; i++) {
>>  		udelay(APPLESMC_MIN_WAIT);
>>  		status = inb(APPLESMC_CMD_PORT);
>> -		if (!(status & 0x01))
>> +		if (!(status & SMC_STATUS_AWAITING_DATA))
>>  			break;
>>  		data = inb(APPLESMC_DATA_PORT);
>>  	}
>> @@ -275,7 +295,7 @@ static int write_smc(u8 cmd, const char *key, const u8 *buffer, u8 len)
>>  	}
>>  
>>  	for (i = 0; i < len; i++) {
>> -		if (send_byte(buffer[i], APPLESMC_DATA_PORT)) {
>> +		if (send_byte_data(buffer[i], APPLESMC_DATA_PORT, i == len - 1)) {
>>  			pr_warn("%s: write data fail\n", key);
>>  			return -EIO;
>>  		}
>>
> 
>

Andreas Kemnade Nov. 9, 2020, 8:44 a.m. UTC | #7

On Sun, 8 Nov 2020 11:14:29 +0100
Henrik Rydberg <[e-mail]> wrote:

> On Sun, Nov 08, 2020 at 09:35:28AM +0100, Henrik Rydberg wrote:
> > Hi Brad,
> > 
> > On 2020-11-08 02:00, Brad Campbell wrote:  
> > > G'day Henrik,
> > > 
> > > I noticed you'd also loosened up the requirement for SMC_STATUS_BUSY in read_smc(). I assume
> > > that causes problems on the early Macbook. This is revised on the one sent earlier.
> > > If you could test this on your Air1,1 it'd be appreciated.  
> > 
> > No, I managed to screw up the patch; you can see that I carefully added the
> > same treatment for the read argument, being unsure if the BUSY state would
> > remain during the AVAILABLE data phase. I can check that again, but
> > unfortunately the patch in this email shows the same problem.
> > 
> > I think it may be worthwhile to rethink the behavior of wait_status() here.
> > If one machine shows no change after a certain status bit change, then
> > perhaps the others share that behavior, and we are waiting in vain. Just
> > imagine how many years of cpu that is, combined. ;-)  
> 
> Here is a modification along that line.
> 
> Compared to your latest version, this one has wait_status() return the
> actual status on success. Instead of waiting for BUSY, it waits for
> the other status bits, and checks BUSY afterwards. So as not to wait
> unneccesarily, the udelay() is placed together with the single
> outb(). The return value of send_byte_data() is augmented with
> -EAGAIN, which is then used in send_command() to create the resend
> loop.
> 
> I reach 41 reads per second on the MBA1,1 with this version, which is
> getting close to the performance prior to the problems.
> 
> From b4405457f4ba07cff7b7e4f48c47668bee176a25 Mon Sep 17 00:00:00 2001
> From: Brad Campbell <[e-mail]>
> Date: Sun, 8 Nov 2020 12:00:03 +1100
> Subject: [PATCH] hwmon: (applesmc) Re-work SMC comms
> 
> Commit fff2d0f701e6 ("hwmon: (applesmc) avoid overlong udelay()")
> introduced an issue whereby communication with the SMC became
> unreliable with write errors like :
> 
> [  120.378614] applesmc: send_byte(0x00, 0x0300) fail: 0x40
> [  120.378621] applesmc: LKSB: write data fail
> [  120.512782] applesmc: send_byte(0x00, 0x0300) fail: 0x40
> [  120.512787] applesmc: LKSB: write data fail
> 
> The original code appeared to be timing sensitive and was not reliable
> with the timing changes in the aforementioned commit.
> 
> This patch re-factors the SMC communication to remove the timing
> dependencies and restore function with the changes previously
> committed.
> 
> Tested on : MacbookAir6,2 MacBookPro11,1 iMac12,2, MacBookAir1,1,
> MacBookAir3,1
> 
> Fixes: fff2d0f701e6 ("hwmon: (applesmc) avoid overlong udelay()")
> Reported-by: Andreas Kemnade <[e-mail]>
> Tested-by: Andreas Kemnade <[e-mail]> # MacBookAir6,2
> Acked-by: Arnd Bergmann <[e-mail]>
> Signed-off-by: Brad Campbell <[e-mail]>
> Signed-off-by: Henrik Rydberg <[e-mail]>
> 
> ---
> Changelog : 
> v1 : Inital attempt
> v2 : Address logic and coding style
> v3 : Removed some debug hangover. Added tested-by. Modifications for MacBookAir1,1
> v4 : Do not expect busy state to appear without other state changes
> 

still works here (MacBookAir6,2)

Regards,
Andreas

Brad Campbell Nov. 9, 2020, 9:51 a.m. UTC | #8

On 9/11/20 7:44 pm, Andreas Kemnade wrote:
> On Sun, 8 Nov 2020 11:14:29 +0100
> Henrik Rydberg <[e-mail]> wrote:
> 
>> On Sun, Nov 08, 2020 at 09:35:28AM +0100, Henrik Rydberg wrote:
>>> Hi Brad,
>>>
>>> On 2020-11-08 02:00, Brad Campbell wrote:  
>>>> G'day Henrik,
>>>>
>>>> I noticed you'd also loosened up the requirement for SMC_STATUS_BUSY in read_smc(). I assume
>>>> that causes problems on the early Macbook. This is revised on the one sent earlier.
>>>> If you could test this on your Air1,1 it'd be appreciated.  
>>>
>>> No, I managed to screw up the patch; you can see that I carefully added the
>>> same treatment for the read argument, being unsure if the BUSY state would
>>> remain during the AVAILABLE data phase. I can check that again, but
>>> unfortunately the patch in this email shows the same problem.
>>>
>>> I think it may be worthwhile to rethink the behavior of wait_status() here.
>>> If one machine shows no change after a certain status bit change, then
>>> perhaps the others share that behavior, and we are waiting in vain. Just
>>> imagine how many years of cpu that is, combined. ;-)  
>>
>> Here is a modification along that line.
>>
>> Compared to your latest version, this one has wait_status() return the
>> actual status on success. Instead of waiting for BUSY, it waits for
>> the other status bits, and checks BUSY afterwards. So as not to wait
>> unneccesarily, the udelay() is placed together with the single
>> outb(). The return value of send_byte_data() is augmented with
>> -EAGAIN, which is then used in send_command() to create the resend
>> loop.
>>
>> I reach 41 reads per second on the MBA1,1 with this version, which is
>> getting close to the performance prior to the problems.
>>
>> From b4405457f4ba07cff7b7e4f48c47668bee176a25 Mon Sep 17 00:00:00 2001
>> From: Brad Campbell <[e-mail]>
>> Date: Sun, 8 Nov 2020 12:00:03 +1100
>> Subject: [PATCH] hwmon: (applesmc) Re-work SMC comms
>>
>> Commit fff2d0f701e6 ("hwmon: (applesmc) avoid overlong udelay()")
>> introduced an issue whereby communication with the SMC became
>> unreliable with write errors like :
>>
>> [  120.378614] applesmc: send_byte(0x00, 0x0300) fail: 0x40
>> [  120.378621] applesmc: LKSB: write data fail
>> [  120.512782] applesmc: send_byte(0x00, 0x0300) fail: 0x40
>> [  120.512787] applesmc: LKSB: write data fail
>>
>> The original code appeared to be timing sensitive and was not reliable
>> with the timing changes in the aforementioned commit.
>>
>> This patch re-factors the SMC communication to remove the timing
>> dependencies and restore function with the changes previously
>> committed.
>>
>> Tested on : MacbookAir6,2 MacBookPro11,1 iMac12,2, MacBookAir1,1,
>> MacBookAir3,1
>>
>> Fixes: fff2d0f701e6 ("hwmon: (applesmc) avoid overlong udelay()")
>> Reported-by: Andreas Kemnade <[e-mail]>
>> Tested-by: Andreas Kemnade <[e-mail]> # MacBookAir6,2
>> Acked-by: Arnd Bergmann <[e-mail]>
>> Signed-off-by: Brad Campbell <[e-mail]>
>> Signed-off-by: Henrik Rydberg <[e-mail]>
>>
>> ---
>> Changelog : 
>> v1 : Inital attempt
>> v2 : Address logic and coding style
>> v3 : Removed some debug hangover. Added tested-by. Modifications for MacBookAir1,1
>> v4 : Do not expect busy state to appear without other state changes
>>
> 
> still works here (MacBookAir6,2)

Much appreciated Andreas.

Regards,
Brad

Brad Campbell Nov. 9, 2020, 1:06 p.m. UTC | #9

On 8/11/20 11:04 pm, Henrik Rydberg wrote:
> On 2020-11-08 12:57, Brad Campbell wrote:
>> On 8/11/20 9:14 pm, Henrik Rydberg wrote:
>>> On Sun, Nov 08, 2020 at 09:35:28AM +0100, Henrik Rydberg wrote:
>>>> Hi Brad,
>>>>
>>>> On 2020-11-08 02:00, Brad Campbell wrote:
>>>>> G'day Henrik,
>>>>>
>>>>> I noticed you'd also loosened up the requirement for SMC_STATUS_BUSY in read_smc(). I assume
>>>>> that causes problems on the early Macbook. This is revised on the one sent earlier.
>>>>> If you could test this on your Air1,1 it'd be appreciated.
>>>>
>>>> No, I managed to screw up the patch; you can see that I carefully added the
>>>> same treatment for the read argument, being unsure if the BUSY state would
>>>> remain during the AVAILABLE data phase. I can check that again, but
>>>> unfortunately the patch in this email shows the same problem.
>>>>
>>>> I think it may be worthwhile to rethink the behavior of wait_status() here.
>>>> If one machine shows no change after a certain status bit change, then
>>>> perhaps the others share that behavior, and we are waiting in vain. Just
>>>> imagine how many years of cpu that is, combined. ;-)
>>>
>>> Here is a modification along that line.
>>>
>>> Compared to your latest version, this one has wait_status() return the
>>> actual status on success. Instead of waiting for BUSY, it waits for
>>> the other status bits, and checks BUSY afterwards. So as not to wait
>>> unneccesarily, the udelay() is placed together with the single
>>> outb(). The return value of send_byte_data() is augmented with
>>> -EAGAIN, which is then used in send_command() to create the resend
>>> loop.
>>>
>>> I reach 41 reads per second on the MBA1,1 with this version, which is
>>> getting close to the performance prior to the problems.
>>
>> G'day Henrik,
>>
>> I like this one. It's slower on my laptop (40 rps vs 50 on the MacbookPro11,1) and the same 17 rps on the iMac 12,2 but it's as reliable
>> and if it works for both of yours then I think it's a winner. I can't really diagnose the iMac properly as I'm 2,800KM away and have
>> nobody to reboot it if I kill it. 5.7.2 gives 20 rps, so 17 is ok for me.
>>
>> Andreas, could I ask you to test this one?
>>
>> Odd my original version worked on your Air3,1 and the other 3 machines without retry.
>> I wonder how many commands require retries, how many retires are actually required, and what we are going wrong on the Air1,1 that requires
>> one or more retries.
>>
>> I just feels like a brute force approach because there's something we're missing.
> 
> I would think you are right. There should be a way to follow the status changes in realtime, so one can determine handshake and processing from that information. At least, with this change, we are making the blunt instrument a little smaller.

G'day Henrik,

Out of morbid curiosity I grabbed an older MacOS AppleSMC.kext (10.7) and ran it through the disassembler.

Every read/write to the SMC starts the same way with a check to make sure the SMC is in a sane state. If it's not, a read command is sent to try and kick it back into line :
Wait for 0x04 to clear. This is 1,000,000 iterations of "read status, check if 0x04 is set, delay 10uS".
If it clears, move on. If it doesn't, try and send a read command (just the command 0x10) and wait for the busy flag to clear again with the same loop.

So in theory if the SMC was locked up, it'd be into the weeds for 20 seconds before it pushed the error out.

So, lets say we've waited long enough and the busy flag dropped :

Each command write is :
Wait for 0x02 to clear. This is 1,000,000 iterations of "read status, check if 0x02 is set, delay 10uS".
Send command

Each data byte write is :
Wait for 0x02 to clear. This is 1,000,000 iterations of "read status, check if 0x02 is set, delay 10uS".
Immediate and single status read, check 0x04. If not set, abort.
Send data byte

Each data byte read is :
read staus, wait for 0x01 and 0x04 to be set. delay 10uS and repeat. Abort if fail.

Each timeout is 1,000,000 loops with a 10uS delay.

So aside from the startup set which occurs on *every* read or write set, status checks happen before a command or data write, and not at all after.
Under no circumstances are writes of any kind re-tried, but these timeouts are up to 10 seconds!

That would indicate that the requirement for retries on the early Mac means we're not waiting long enough somewhere. Not that I'm suggesting we do another re-work, but when I get back in front of my iMac which does 17 transactions per second with this driver, I might re-work it similar to the Apple driver and see what happens.

Oh, and it looks like the 0x40 flag that is on mine is the "I have an interrupt pending" flag, and the result should be able to be read from 0x31F. I'll play with that when I get time. That probably explains why IRQ9 screams until the kernel gags it on this machine as it's not being given any love.

Regards,
Brad

Henrik Rydberg Nov. 9, 2020, 5:08 p.m. UTC | #10

Hi Brad,

> Out of morbid curiosity I grabbed an older MacOS AppleSMC.kext (10.7) and ran it through the disassembler.
> 
> Every read/write to the SMC starts the same way with a check to make sure the SMC is in a sane state. If it's not, a read command is sent to try and kick it back into line :
> Wait for 0x04 to clear. This is 1,000,000 iterations of "read status, check if 0x04 is set, delay 10uS".
> If it clears, move on. If it doesn't, try and send a read command (just the command 0x10) and wait for the busy flag to clear again with the same loop.
> 
> So in theory if the SMC was locked up, it'd be into the weeds for 20 seconds before it pushed the error out.
> 
> So, lets say we've waited long enough and the busy flag dropped :
> 
> Each command write is :
> Wait for 0x02 to clear. This is 1,000,000 iterations of "read status, check if 0x02 is set, delay 10uS".
> Send command
> 
> Each data byte write is :
> Wait for 0x02 to clear. This is 1,000,000 iterations of "read status, check if 0x02 is set, delay 10uS".
> Immediate and single status read, check 0x04. If not set, abort.
> Send data byte
> 
> Each data byte read is :
> read staus, wait for 0x01 and 0x04 to be set. delay 10uS and repeat. Abort if fail.
> 
> Each timeout is 1,000,000 loops with a 10uS delay.
> 
> So aside from the startup set which occurs on *every* read or write set, status checks happen before a command or data write, and not at all after.
> Under no circumstances are writes of any kind re-tried, but these timeouts are up to 10 seconds!

Great findings here. But from this, it would seem we are doing almost 
the right thing already, no? The essential difference seems to be that 
where the kext does a read to wake up the SMC, while we retry the first 
command until it works. If would of course be very interesting to know 
if that makes a difference.

> That would indicate that the requirement for retries on the early Mac means we're not waiting long enough somewhere. Not that I'm suggesting we do another re-work, but when I get back in front of my iMac which does 17 transactions per second with this driver, I might re-work it similar to the Apple driver and see what happens.
> 
> Oh, and it looks like the 0x40 flag that is on mine is the "I have an interrupt pending" flag, and the result should be able to be read from 0x31F. I'll play with that when I get time. That probably explains why IRQ9 screams until the kernel gags it on this machine as it's not being given any love.

Sounds good, getting interrupts working would have been nice.

Henrik

Brad Campbell Nov. 9, 2020, 10:52 p.m. UTC | #11

On 10/11/20 4:08 am, Henrik Rydberg wrote:
> Hi Brad,
> 
>> Out of morbid curiosity I grabbed an older MacOS AppleSMC.kext (10.7) and ran it through the disassembler.
>>
>> Every read/write to the SMC starts the same way with a check to make sure the SMC is in a sane state. If it's not, a read command is sent to try and kick it back into line :
>> Wait for 0x04 to clear. This is 1,000,000 iterations of "read status, check if 0x04 is set, delay 10uS".
>> If it clears, move on. If it doesn't, try and send a read command (just the command 0x10) and wait for the busy flag to clear again with the same loop.
>>
>> So in theory if the SMC was locked up, it'd be into the weeds for 20 seconds before it pushed the error out.
>>
>> So, lets say we've waited long enough and the busy flag dropped :
>>
>> Each command write is :
>> Wait for 0x02 to clear. This is 1,000,000 iterations of "read status, check if 0x02 is set, delay 10uS".
>> Send command
>>
>> Each data byte write is :
>> Wait for 0x02 to clear. This is 1,000,000 iterations of "read status, check if 0x02 is set, delay 10uS".
>> Immediate and single status read, check 0x04. If not set, abort.
>> Send data byte
>>
>> Each data byte read is :
>> read staus, wait for 0x01 and 0x04 to be set. delay 10uS and repeat. Abort if fail.
>>
>> Each timeout is 1,000,000 loops with a 10uS delay.
>>
>> So aside from the startup set which occurs on *every* read or write set, status checks happen before a command or data write, and not at all after.
>> Under no circumstances are writes of any kind re-tried, but these timeouts are up to 10 seconds!
> 
> Great findings here. But from this, it would seem we are doing almost the right thing already, no? The essential difference seems to be that where the kext does a read to wake up the SMC, while we retry the first command until it works. If would of course be very interesting to know if that makes a difference.

It does make a significant difference here. It doesn't use the read to wake up the SMC as such. It appears to use the read to get the SMC in sync with the driver. It only performs the extra read if the busy line is still active when it shouldn't be and provided the driver plays by the rules it only seems to do it once on init and only if the SMC thinks it's mid command (so has been left in an undefined state).

Re-working the driver to use the logic described my MacbookPro11,1 goes from 40 reads/sec to 125 reads/sec. My iMac12,2 goes from 17 reads/sec to 30.

I have one issue to understand before I post a patch.

If the SMC is in an inconsistent state (as in busy persistently high) then the driver issues a read command and waits for busy to drop (and it does, and bit 0x08 goes high on my laptop but nothing checks that). That is to a point expected based on the poking I did early on in this process.
On the other hand, when we perform a read or a write, the driver issues a read or write command and the following commands to send the key rely on the busy bit being set.

Now, in practice this works, and I've sent spurious commands to get things out of sync and after a long wait it syncs back up. I just want to try and understand the state machine inside the SMC a bit better before posting another patch.

 
>> That would indicate that the requirement for retries on the early Mac means we're not waiting long enough somewhere. Not that I'm suggesting we do another re-work, but when I get back in front of my iMac which does 17 transactions per second with this driver, I might re-work it similar to the Apple driver and see what happens.
>>
>> Oh, and it looks like the 0x40 flag that is on mine is the "I have an interrupt pending" flag, and the result should be able to be read from 0x31F. I'll play with that when I get time. That probably explains why IRQ9 screams until the kernel gags it on this machine as it's not being given any love.
> 
> Sounds good, getting interrupts working would have been nice.

I've put it on my list of things to look at. There's a lot of magic constants in the interrupt handler.

Regards,
Brad

Brad Campbell Nov. 10, 2020, 2:04 a.m. UTC | #12

On 9/11/20 3:06 am, Guenter Roeck wrote:
> On 11/8/20 2:14 AM, Henrik Rydberg wrote:
>> On Sun, Nov 08, 2020 at 09:35:28AM +0100, Henrik Rydberg wrote:
>>> Hi Brad,
>>>
>>> On 2020-11-08 02:00, Brad Campbell wrote:
>>>> G'day Henrik,
>>>>
>>>> I noticed you'd also loosened up the requirement for SMC_STATUS_BUSY in read_smc(). I assume
>>>> that causes problems on the early Macbook. This is revised on the one sent earlier.
>>>> If you could test this on your Air1,1 it'd be appreciated.
>>>
>>> No, I managed to screw up the patch; you can see that I carefully added the
>>> same treatment for the read argument, being unsure if the BUSY state would
>>> remain during the AVAILABLE data phase. I can check that again, but
>>> unfortunately the patch in this email shows the same problem.
>>>
>>> I think it may be worthwhile to rethink the behavior of wait_status() here.
>>> If one machine shows no change after a certain status bit change, then
>>> perhaps the others share that behavior, and we are waiting in vain. Just
>>> imagine how many years of cpu that is, combined. ;-)
>>
>> Here is a modification along that line.
>>
> 
> Please resend this patch as stand-alone v4 patch. If sent like it was sent here,
> it doesn't make it into patchwork, and is thus not only difficult to apply but
> may get lost, and it is all but impossible to find and apply all tags.
> Also, prior to Henrik's Signed=off-by: there should be a one-line explanation
> of the changes made.
> 
> Thanks,
> Guenter
> 
>> Compared to your latest version, this one has wait_status() return the
>> actual status on success. Instead of waiting for BUSY, it waits for
>> the other status bits, and checks BUSY afterwards. So as not to wait
>> unneccesarily, the udelay() is placed together with the single
>> outb(). The return value of send_byte_data() is augmented with
>> -EAGAIN, which is then used in send_command() to create the resend
>> loop.
>>
>> I reach 41 reads per second on the MBA1,1 with this version, which is
>> getting close to the performance prior to the problems.
>>

Can I get an opinion on this wait statement please?

The apple driver uses a loop with a million (1,000,000) retries spaced with a 10uS delay.

In my testing on 2 machines, we don't busy wait more than about 2 loops.
Replacing a small udelay with the usleep_range kills performance.
With the following (do 10 fast checks before we start sleeping) I nearly triple the performance
of the driver on my laptop, and double it on my iMac. This is on an otherwise unmodified version of
Henriks v4 submission.

Yes, given the timeouts I know it's a ridiculous loop condition.

static int wait_status(u8 val, u8 mask)
{
	unsigned long end = jiffies + (APPLESMC_MAX_WAIT * HZ) / USEC_PER_SEC;
	u8 status;
	int i;

	for (i=1; i < 1000000; i++) {
		status = inb(APPLESMC_CMD_PORT);
		if ((status & mask) == val)
			return status;
		/* timeout: give up */
		if (time_after(jiffies, end))
			break;
		if (i < 10)
			udelay(10);
		else
			usleep_range(APPLESMC_MIN_WAIT, APPLESMC_MIN_WAIT * 16);
	}
	return -EIO;
}

Regards,
Brad

Guenter Roeck Nov. 10, 2020, 4:55 a.m. UTC | #13

On Tue, Nov 10, 2020 at 01:04:04PM +1100, Brad Campbell wrote:
> On 9/11/20 3:06 am, Guenter Roeck wrote:
> > On 11/8/20 2:14 AM, Henrik Rydberg wrote:
> >> On Sun, Nov 08, 2020 at 09:35:28AM +0100, Henrik Rydberg wrote:
> >>> Hi Brad,
> >>>
> >>> On 2020-11-08 02:00, Brad Campbell wrote:
> >>>> G'day Henrik,
> >>>>
> >>>> I noticed you'd also loosened up the requirement for SMC_STATUS_BUSY in read_smc(). I assume
> >>>> that causes problems on the early Macbook. This is revised on the one sent earlier.
> >>>> If you could test this on your Air1,1 it'd be appreciated.
> >>>
> >>> No, I managed to screw up the patch; you can see that I carefully added the
> >>> same treatment for the read argument, being unsure if the BUSY state would
> >>> remain during the AVAILABLE data phase. I can check that again, but
> >>> unfortunately the patch in this email shows the same problem.
> >>>
> >>> I think it may be worthwhile to rethink the behavior of wait_status() here.
> >>> If one machine shows no change after a certain status bit change, then
> >>> perhaps the others share that behavior, and we are waiting in vain. Just
> >>> imagine how many years of cpu that is, combined. ;-)
> >>
> >> Here is a modification along that line.
> >>
> > 
> > Please resend this patch as stand-alone v4 patch. If sent like it was sent here,
> > it doesn't make it into patchwork, and is thus not only difficult to apply but
> > may get lost, and it is all but impossible to find and apply all tags.
> > Also, prior to Henrik's Signed=off-by: there should be a one-line explanation
> > of the changes made.
> > 
> > Thanks,
> > Guenter
> > 
> >> Compared to your latest version, this one has wait_status() return the
> >> actual status on success. Instead of waiting for BUSY, it waits for
> >> the other status bits, and checks BUSY afterwards. So as not to wait
> >> unneccesarily, the udelay() is placed together with the single
> >> outb(). The return value of send_byte_data() is augmented with
> >> -EAGAIN, which is then used in send_command() to create the resend
> >> loop.
> >>
> >> I reach 41 reads per second on the MBA1,1 with this version, which is
> >> getting close to the performance prior to the problems.
> >>
> 
> Can I get an opinion on this wait statement please?
> 
> The apple driver uses a loop with a million (1,000,000) retries spaced with a 10uS delay.
> 
> In my testing on 2 machines, we don't busy wait more than about 2 loops.
> Replacing a small udelay with the usleep_range kills performance.
> With the following (do 10 fast checks before we start sleeping) I nearly triple the performance
> of the driver on my laptop, and double it on my iMac. This is on an otherwise unmodified version of
> Henriks v4 submission.
> 
> Yes, given the timeouts I know it's a ridiculous loop condition.
> 
> static int wait_status(u8 val, u8 mask)
> {
> 	unsigned long end = jiffies + (APPLESMC_MAX_WAIT * HZ) / USEC_PER_SEC;
> 	u8 status;
> 	int i;
> 
> 	for (i=1; i < 1000000; i++) {

The minimum wait time is 10 us, or 16uS after the first 10
attempts. 1000000 * 10 = 10 seconds. I mean, it would make
some sense to limit the loop to APPLESMC_MAX_WAIT /
APPLESMC_MIN_WAIT iterations, but why 1,000,000 ?

> 		status = inb(APPLESMC_CMD_PORT);
> 		if ((status & mask) == val)
> 			return status;
> 		/* timeout: give up */
> 		if (time_after(jiffies, end))
> 			break;
> 		if (i < 10)
> 			udelay(10);
> 		else
> 			usleep_range(APPLESMC_MIN_WAIT, APPLESMC_MIN_WAIT * 16);

The original code had the exponential wait time increase.
I don't really see the point of changing that. I'd suggest
to keep the exponential increase but change the code to
something like
		if (us < APPLESMC_MIN_WAIT * 4)
			udelay(us)
		else
			usleep_range(us, us * 16);

Effectively that means the first wait would be 16 uS,
followed by 32 uS, followed by increasingly larger sleep
times. I don't know the relevance of APPLESMC_MIN_WAIT
being set to 16, but if you'd want to start with smaller
wait times you could reduce it to 8. If you are concerned
about excessively large sleep times you could reduce
the span from us..us*16 to, say, us..us*4 or us..us*2.

Thanks,
Guenter

> 	}
> 	return -EIO;
> }
> 
> Regards,
> Brad

Brad Campbell Nov. 10, 2020, 5:40 a.m. UTC | #14

On 10/11/20 3:55 pm, Guenter Roeck wrote:
> On Tue, Nov 10, 2020 at 01:04:04PM +1100, Brad Campbell wrote:
>> On 9/11/20 3:06 am, Guenter Roeck wrote:
>>> On 11/8/20 2:14 AM, Henrik Rydberg wrote:
>>>> On Sun, Nov 08, 2020 at 09:35:28AM +0100, Henrik Rydberg wrote:
>>>>> Hi Brad,
>>>>>
>>>>> On 2020-11-08 02:00, Brad Campbell wrote:
>>>>>> G'day Henrik,
>>>>>>
>>>>>> I noticed you'd also loosened up the requirement for SMC_STATUS_BUSY in read_smc(). I assume
>>>>>> that causes problems on the early Macbook. This is revised on the one sent earlier.
>>>>>> If you could test this on your Air1,1 it'd be appreciated.
>>>>>
>>>>> No, I managed to screw up the patch; you can see that I carefully added the
>>>>> same treatment for the read argument, being unsure if the BUSY state would
>>>>> remain during the AVAILABLE data phase. I can check that again, but
>>>>> unfortunately the patch in this email shows the same problem.
>>>>>
>>>>> I think it may be worthwhile to rethink the behavior of wait_status() here.
>>>>> If one machine shows no change after a certain status bit change, then
>>>>> perhaps the others share that behavior, and we are waiting in vain. Just
>>>>> imagine how many years of cpu that is, combined. ;-)
>>>>
>>>> Here is a modification along that line.
>>>>
>>>
>>> Please resend this patch as stand-alone v4 patch. If sent like it was sent here,
>>> it doesn't make it into patchwork, and is thus not only difficult to apply but
>>> may get lost, and it is all but impossible to find and apply all tags.
>>> Also, prior to Henrik's Signed=off-by: there should be a one-line explanation
>>> of the changes made.
>>>
>>> Thanks,
>>> Guenter
>>>
>>>> Compared to your latest version, this one has wait_status() return the
>>>> actual status on success. Instead of waiting for BUSY, it waits for
>>>> the other status bits, and checks BUSY afterwards. So as not to wait
>>>> unneccesarily, the udelay() is placed together with the single
>>>> outb(). The return value of send_byte_data() is augmented with
>>>> -EAGAIN, which is then used in send_command() to create the resend
>>>> loop.
>>>>
>>>> I reach 41 reads per second on the MBA1,1 with this version, which is
>>>> getting close to the performance prior to the problems.
>>>>
>>
>> Can I get an opinion on this wait statement please?
>>
>> The apple driver uses a loop with a million (1,000,000) retries spaced with a 10uS delay.
>>
>> In my testing on 2 machines, we don't busy wait more than about 2 loops.
>> Replacing a small udelay with the usleep_range kills performance.
>> With the following (do 10 fast checks before we start sleeping) I nearly triple the performance
>> of the driver on my laptop, and double it on my iMac. This is on an otherwise unmodified version of
>> Henriks v4 submission.
>>
>> Yes, given the timeouts I know it's a ridiculous loop condition.
>>
>> static int wait_status(u8 val, u8 mask)
>> {
>> 	unsigned long end = jiffies + (APPLESMC_MAX_WAIT * HZ) / USEC_PER_SEC;
>> 	u8 status;
>> 	int i;
>>
>> 	for (i=1; i < 1000000; i++) {
> 
> The minimum wait time is 10 us, or 16uS after the first 10
> attempts. 1000000 * 10 = 10 seconds. I mean, it would make
> some sense to limit the loop to APPLESMC_MAX_WAIT /
> APPLESMC_MIN_WAIT iterations, but why 1,000,000 ?

I had to pick a big number and it was easy to punch in 6 zeros as that is what is in
the OSX driver. In this instance it's more a proof of concept rather than sane example
because it'll either abort on timeout or return the correct status anyway.
Could also have been a while (true) {} but then I'd need to manually increment i.

>> 		status = inb(APPLESMC_CMD_PORT);
>> 		if ((status & mask) == val)
>> 			return status;
>> 		/* timeout: give up */
>> 		if (time_after(jiffies, end))
>> 			break;
>> 		if (i < 10)
>> 			udelay(10);
>> 		else
>> 			usleep_range(APPLESMC_MIN_WAIT, APPLESMC_MIN_WAIT * 16);
> 
> The original code had the exponential wait time increase.
> I don't really see the point of changing that. I'd suggest
> to keep the exponential increase but change the code to
> something like
> 		if (us < APPLESMC_MIN_WAIT * 4)
> 			udelay(us)
> 		else
> 			usleep_range(us, us * 16);

The main reason I dropped the exponential was best case on this laptop the modified code with exponential
wait as described above increase increases the performance from ~40 -> 62 reads/sec, whereas the version 
I posted with the first 10 loops at 10uS goes from ~40 -> 100 reads/sec.

About 95% of waits never get past a few of iterations of that loop (so ~30-60uS). With a
modified exponential starting at 8uS a 30uS requirement ends up at 56uS. If it needed 60us with
the original we end up waiting 120uS.

If it needs longer than 120uS it's rare enough that a bigger sleep isn't going to cause much
of a performance hit.

Getting completely pathological and busy waiting with a fixed 10uS delay like the OSX driver
does give about 125 reads/sec but I was trying to find a balance and 10 loops seemed to hit that mark.
 
> Effectively that means the first wait would be 16 uS,
> followed by 32 uS, followed by increasingly larger sleep
> times. I don't know the relevance of APPLESMC_MIN_WAIT
> being set to 16, but if you'd want to start with smaller
> wait times you could reduce it to 8. If you are concerned
> about excessively large sleep times you could reduce
> the span from us..us*16 to, say, us..us*4 or us..us*2.

I was tossing up here between the overhead required to manage a tighter usleep_range
vs some extra udelays. 

It's not exactly a performance sensitive driver, but I thought there might be a balance to be
struck between performance and simplicity. The exponential delay always struck me as odd.

If the preference is to leave it as is or modify as suggested I'm ok with that too.
Appreciate the input.

Regards,
Brad

Guenter Roeck Nov. 10, 2020, 4:02 p.m. UTC | #15

On Tue, Nov 10, 2020 at 04:40:23PM +1100, Brad Campbell wrote:
> On 10/11/20 3:55 pm, Guenter Roeck wrote:
> > On Tue, Nov 10, 2020 at 01:04:04PM +1100, Brad Campbell wrote:
> >> On 9/11/20 3:06 am, Guenter Roeck wrote:
> >>> On 11/8/20 2:14 AM, Henrik Rydberg wrote:
> >>>> On Sun, Nov 08, 2020 at 09:35:28AM +0100, Henrik Rydberg wrote:
> >>>>> Hi Brad,
> >>>>>
> >>>>> On 2020-11-08 02:00, Brad Campbell wrote:
> >>>>>> G'day Henrik,
> >>>>>>
> >>>>>> I noticed you'd also loosened up the requirement for SMC_STATUS_BUSY in read_smc(). I assume
> >>>>>> that causes problems on the early Macbook. This is revised on the one sent earlier.
> >>>>>> If you could test this on your Air1,1 it'd be appreciated.
> >>>>>
> >>>>> No, I managed to screw up the patch; you can see that I carefully added the
> >>>>> same treatment for the read argument, being unsure if the BUSY state would
> >>>>> remain during the AVAILABLE data phase. I can check that again, but
> >>>>> unfortunately the patch in this email shows the same problem.
> >>>>>
> >>>>> I think it may be worthwhile to rethink the behavior of wait_status() here.
> >>>>> If one machine shows no change after a certain status bit change, then
> >>>>> perhaps the others share that behavior, and we are waiting in vain. Just
> >>>>> imagine how many years of cpu that is, combined. ;-)
> >>>>
> >>>> Here is a modification along that line.
> >>>>
> >>>
> >>> Please resend this patch as stand-alone v4 patch. If sent like it was sent here,
> >>> it doesn't make it into patchwork, and is thus not only difficult to apply but
> >>> may get lost, and it is all but impossible to find and apply all tags.
> >>> Also, prior to Henrik's Signed=off-by: there should be a one-line explanation
> >>> of the changes made.
> >>>
> >>> Thanks,
> >>> Guenter
> >>>
> >>>> Compared to your latest version, this one has wait_status() return the
> >>>> actual status on success. Instead of waiting for BUSY, it waits for
> >>>> the other status bits, and checks BUSY afterwards. So as not to wait
> >>>> unneccesarily, the udelay() is placed together with the single
> >>>> outb(). The return value of send_byte_data() is augmented with
> >>>> -EAGAIN, which is then used in send_command() to create the resend
> >>>> loop.
> >>>>
> >>>> I reach 41 reads per second on the MBA1,1 with this version, which is
> >>>> getting close to the performance prior to the problems.
> >>>>
> >>
> >> Can I get an opinion on this wait statement please?
> >>
> >> The apple driver uses a loop with a million (1,000,000) retries spaced with a 10uS delay.
> >>
> >> In my testing on 2 machines, we don't busy wait more than about 2 loops.
> >> Replacing a small udelay with the usleep_range kills performance.
> >> With the following (do 10 fast checks before we start sleeping) I nearly triple the performance
> >> of the driver on my laptop, and double it on my iMac. This is on an otherwise unmodified version of
> >> Henriks v4 submission.
> >>
> >> Yes, given the timeouts I know it's a ridiculous loop condition.
> >>
> >> static int wait_status(u8 val, u8 mask)
> >> {
> >> 	unsigned long end = jiffies + (APPLESMC_MAX_WAIT * HZ) / USEC_PER_SEC;
> >> 	u8 status;
> >> 	int i;
> >>
> >> 	for (i=1; i < 1000000; i++) {
> > 
> > The minimum wait time is 10 us, or 16uS after the first 10
> > attempts. 1000000 * 10 = 10 seconds. I mean, it would make
> > some sense to limit the loop to APPLESMC_MAX_WAIT /
> > APPLESMC_MIN_WAIT iterations, but why 1,000,000 ?
> 
> I had to pick a big number and it was easy to punch in 6 zeros as that is what is in
> the OSX driver. In this instance it's more a proof of concept rather than sane example
> because it'll either abort on timeout or return the correct status anyway.
> Could also have been a while (true) {} but then I'd need to manually increment i.
> 
> >> 		status = inb(APPLESMC_CMD_PORT);
> >> 		if ((status & mask) == val)
> >> 			return status;
> >> 		/* timeout: give up */
> >> 		if (time_after(jiffies, end))
> >> 			break;
> >> 		if (i < 10)
> >> 			udelay(10);
> >> 		else
> >> 			usleep_range(APPLESMC_MIN_WAIT, APPLESMC_MIN_WAIT * 16);
> > 
> > The original code had the exponential wait time increase.
> > I don't really see the point of changing that. I'd suggest
> > to keep the exponential increase but change the code to
> > something like
> > 		if (us < APPLESMC_MIN_WAIT * 4)
> > 			udelay(us)
> > 		else
> > 			usleep_range(us, us * 16);
> 
> The main reason I dropped the exponential was best case on this laptop the modified code with exponential
> wait as described above increase increases the performance from ~40 -> 62 reads/sec, whereas the version 
> I posted with the first 10 loops at 10uS goes from ~40 -> 100 reads/sec.
> 
> About 95% of waits never get past a few of iterations of that loop (so ~30-60uS). With a
> modified exponential starting at 8uS a 30uS requirement ends up at 56uS. If it needed 60us with
> the original we end up waiting 120uS.
> 
> If it needs longer than 120uS it's rare enough that a bigger sleep isn't going to cause much
> of a performance hit.
> 
> Getting completely pathological and busy waiting with a fixed 10uS delay like the OSX driver
> does give about 125 reads/sec but I was trying to find a balance and 10 loops seemed to hit that mark.
>  
> > Effectively that means the first wait would be 16 uS,
> > followed by 32 uS, followed by increasingly larger sleep
> > times. I don't know the relevance of APPLESMC_MIN_WAIT
> > being set to 16, but if you'd want to start with smaller
> > wait times you could reduce it to 8. If you are concerned
> > about excessively large sleep times you could reduce
> > the span from us..us*16 to, say, us..us*4 or us..us*2.
> 
> I was tossing up here between the overhead required to manage a tighter usleep_range
> vs some extra udelays. 
> 
> It's not exactly a performance sensitive driver, but I thought there might be a balance to be
> struck between performance and simplicity. The exponential delay always struck me as odd.
> 
> If the preference is to leave it as is or modify as suggested I'm ok with that too.
> Appreciate the input.

Ok, not worth arguing about.

Guenter

> 
> Regards,
> Brad

Patch

diff --git a/drivers/hwmon/applesmc.c b/drivers/hwmon/applesmc.c
index a18887990f4a..3e968abb37aa 100644
--- a/drivers/hwmon/applesmc.c
+++ b/drivers/hwmon/applesmc.c
@@ -32,6 +32,7 @@ 
 #include <linux/hwmon.h>
 #include <linux/workqueue.h>
 #include <linux/err.h>
+#include <linux/bits.h>
 
 /* data port used by Apple SMC */
 #define APPLESMC_DATA_PORT	0x300
@@ -42,6 +43,11 @@ 
 
 #define APPLESMC_MAX_DATA_LENGTH 32
 
+/* Apple SMC status bits */
+#define SMC_STATUS_AWAITING_DATA  BIT(0) /* SMC has data waiting */
+#define SMC_STATUS_IB_CLOSED      BIT(1) /* Will ignore any input */
+#define SMC_STATUS_BUSY           BIT(2) /* Command in progress */
+
 /* wait up to 128 ms for a status change. */
 #define APPLESMC_MIN_WAIT	0x0010
 #define APPLESMC_RETRY_WAIT	0x0100
@@ -151,65 +157,73 @@  static unsigned int key_at_index;
 static struct workqueue_struct *applesmc_led_wq;
 
 /*
- * wait_read - Wait for a byte to appear on SMC port. Callers must
- * hold applesmc_lock.
+ * Wait for specific status bits with a mask on the SMC
+ * Used before and after writes, and before reads
  */
-static int wait_read(void)
+
+static int wait_status(u8 val, u8 mask)
 {
 	unsigned long end = jiffies + (APPLESMC_MAX_WAIT * HZ) / USEC_PER_SEC;
 	u8 status;
 	int us;
 
+	udelay(APPLESMC_MIN_WAIT);
 	for (us = APPLESMC_MIN_WAIT; us < APPLESMC_MAX_WAIT; us <<= 1) {
-		usleep_range(us, us * 16);
 		status = inb(APPLESMC_CMD_PORT);
-		/* read: wait for smc to settle */
-		if (status & 0x01)
+		if ((status & mask) == val)
 			return 0;
 		/* timeout: give up */
 		if (time_after(jiffies, end))
 			break;
+		usleep_range(us, us * 16);
 	}
-
-	pr_warn("wait_read() fail: 0x%02x\n", status);
 	return -EIO;
 }
 
 /*
- * send_byte - Write to SMC port, retrying when necessary. Callers
+ * send_byte_data - Write to SMC data port. Callers
  * must hold applesmc_lock.
+ * Parameter skip must be true on the last write of any
+ * command or it'll time out.
  */
-static int send_byte(u8 cmd, u16 port)
+
+static int send_byte_data(u8 cmd, u16 port, bool skip)
 {
-	u8 status;
-	int us;
-	unsigned long end = jiffies + (APPLESMC_MAX_WAIT * HZ) / USEC_PER_SEC;
+	int ret;
 
+	ret = wait_status(SMC_STATUS_BUSY, SMC_STATUS_BUSY | SMC_STATUS_IB_CLOSED);
+	if (ret)
+		return ret;
 	outb(cmd, port);
-	for (us = APPLESMC_MIN_WAIT; us < APPLESMC_MAX_WAIT; us <<= 1) {
-		usleep_range(us, us * 16);
-		status = inb(APPLESMC_CMD_PORT);
-		/* write: wait for smc to settle */
-		if (status & 0x02)
-			continue;
-		/* ready: cmd accepted, return */
-		if (status & 0x04)
-			return 0;
-		/* timeout: give up */
-		if (time_after(jiffies, end))
-			break;
-		/* busy: long wait and resend */
-		udelay(APPLESMC_RETRY_WAIT);
-		outb(cmd, port);
-	}
+	return wait_status(skip ? 0 : SMC_STATUS_BUSY, SMC_STATUS_BUSY);
+}
 
-	pr_warn("send_byte(0x%02x, 0x%04x) fail: 0x%02x\n", cmd, port, status);
-	return -EIO;
+static int send_byte(u8 cmd, u16 port)
+{
+	return send_byte_data(cmd, port, false);
 }
 
+/*
+ * send_command - Write a command to the SMC. Callers must hold applesmc_lock.
+ * If SMC is in undefined state, any new command write resets the state machine.
+ */
+
 static int send_command(u8 cmd)
 {
-	return send_byte(cmd, APPLESMC_CMD_PORT);
+	int ret;
+	int i;
+
+	for (i = 0; i < 16; i++) {
+		ret = wait_status(0, SMC_STATUS_IB_CLOSED);
+		if (ret)
+			return ret;
+
+		outb(cmd, APPLESMC_CMD_PORT);
+		ret = wait_status(SMC_STATUS_BUSY, SMC_STATUS_BUSY);
+		if (!ret)
+			return ret;
+	}
+	return -EIO;
 }
 
 static int send_argument(const char *key)
@@ -239,7 +253,8 @@  static int read_smc(u8 cmd, const char *key, u8 *buffer, u8 len)
 	}
 
 	for (i = 0; i < len; i++) {
-		if (wait_read()) {
+		if (wait_status(SMC_STATUS_AWAITING_DATA,
+				SMC_STATUS_AWAITING_DATA | SMC_STATUS_IB_CLOSED)) {
 			pr_warn("%.4s: read data[%d] fail\n", key, i);
 			return -EIO;
 		}
@@ -250,7 +265,7 @@  static int read_smc(u8 cmd, const char *key, u8 *buffer, u8 len)
 	for (i = 0; i < 16; i++) {
 		udelay(APPLESMC_MIN_WAIT);
 		status = inb(APPLESMC_CMD_PORT);
-		if (!(status & 0x01))
+		if (!(status & SMC_STATUS_AWAITING_DATA))
 			break;
 		data = inb(APPLESMC_DATA_PORT);
 	}
@@ -275,7 +290,7 @@  static int write_smc(u8 cmd, const char *key, const u8 *buffer, u8 len)
 	}
 
 	for (i = 0; i < len; i++) {
-		if (send_byte(buffer[i], APPLESMC_DATA_PORT)) {
+		if (send_byte_data(buffer[i], APPLESMC_DATA_PORT, i == len - 1)) {
 			pr_warn("%s: write data fail\n", key);
 			return -EIO;
 		}