Re: [REGRESSION] hwmon: (applesmc) avoid overlong udelay()

Brad Campbell
2020-11-03T05:58:19Z

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

On 3/11/20 10:56 am, Brad Campbell wrote:

>
> I've examined the code in VirtualSMC and I'm not convinced we were not waiting on the wrong bits.
>
> #define SMC_STATUS_AWAITING_DATA  BIT0  ///< Ready to read data.
> #define SMC_STATUS_IB_CLOSED      BIT1  /// A write is pending.
> #define SMC_STATUS_BUSY           BIT2  ///< Busy processing a command.
> #define SMC_STATUS_GOT_COMMAND    BIT3  ///< The last input was a command.
> #define SMC_STATUS_UKN_0x16       BIT4
> #define SMC_STATUS_KEY_DONE       BIT5
> #define SMC_STATUS_READY          BIT6  // Ready to work
> #define SMC_STATUS_UKN_0x80       BIT7  // error
>
> Any chance you could try this patch? It's ugly, hacked together and currently fairly undocumented, but if it works I'll figure out how to clean it up (suggestions welcome).
> It works on my MacbookPro 11,1.

I had some time so I spent a bit of time refactoring and trying to clarify the magic numbers.

I also did some fuzzing of the SMC and figured out where we can loosen the masks.
This has some debug code in it to identify if any wait loops exceed 1 loop and if the SMC is reporting anything other than a clear "I'm waiting" prior to each command.

You might see some of these :
[ 51.316202] applesmc: wait_status looping 2: 0x44, 0x40, 0x4e
[ 60.002547] applesmc: wait_status looping 2: 0x44, 0x40, 0x4e
[ 60.130754] applesmc: wait_status looping 2: 0x44, 0x40, 0x4e

I did some heavy tests and found that with the delays at the bottom of the loop about 50% of calls required no delay at all before a read or write and the other 50% require a single delay.
I can count on one hand the number of times it's exceeded 1 loop, and the max thus far has been 5 loops.

We've been treating bit 0x04 as an ack, but from my testing on the machine and what I've seen in the SMC emulator code it actually means "I'm busy in the middle of a command". Bit 0x02 seems to mean "I'm doing something and I *will* ignore anything you send me".
Bit 0x08 means "The last thing I got was a valid command, so start sending me data".

By testing and waiting for 0x02 to clear before sending or reading I haven't seen any need for retries.

On my unit bit 0x40 is always active. It may not be on others. The emulator calls it a status ready, so it's tested for but that is consolidated in wait_status so it can be commented out if it doesn't work on your machine.

The thing with bit 0x04 is the SMC clears it when it's no longer busy. So the last byte of data sent for a command sees it clear that bit. That explains the timeouts but the command still works. As far as the SMC is concerned it's got all the data and gone off to do its thing, but applesmc was waiting for the bit to be set. When it's in the middle of a command (from the first command byte until the last data byte is received) I've never seen bit 0x04 cleared, so using it as an "ack" works, but as said upward in the thread "probably by accident".

So this code tests for an "idle" SMC before it sends a command. In this context idle just means bit 0x02 isn't set. If the SMC gets into an undefined state it can leave other bits set, but a new write with a valid command will reset the internal state machine and bring it back into line. Bit 0x08 should always be set after it has received a valid command.

I've gone belt and braces by checking the status before and after each command, but with the intention of trying to catch and log anything that goes awry. Like I said above, in 50% of cases I see zero delays required so I thought testing before the delay was a worthwhile win.

If anyone with a Mac having a conventional SMC and seeing issues on 5.9 could test this it'd be appreciated. I'm not saying this code is "correct", but it "works for me".

If anyone actually knows what they're doing and wants to "correct" me, it'd be appreciated also.

Regards,
Brad

[-- Attachment #2: smc.patch.5 --]
[-- Type: text/plain, Size: 6173 bytes --]

diff --git a/drivers/hwmon/applesmc.c b/drivers/hwmon/applesmc.c
index a18887990f4a..abb06fbe7bc1 100644
--- a/drivers/hwmon/applesmc.c
+++ b/drivers/hwmon/applesmc.c
@@ -42,6 +42,16 @@

#define APPLESMC_MAX_DATA_LENGTH 32

+/* Apple SMC status bits */
+#define SMC_STATUS_AWAITING_DATA 0x01 ///< Data waiting to be read
+#define SMC_STATUS_IB_CLOSED 0x02 /// A write is pending / will ignore input
+#define SMC_STATUS_BUSY 0x04 ///< Busy in the middle of a command.
+#define SMC_STATUS_GOT_COMMAND 0x08 ///< The last input was a command.
+#define SMC_STATUS_UKN_0x16 0x10
+#define SMC_STATUS_KEY_DONE 0x20
+#define SMC_STATUS_READY 0x40 // Ready to work
+#define SMC_STATUS_UKN_0x80 0x80 // error
+
/* wait up to 128 ms for a status change. */
#define APPLESMC_MIN_WAIT 0x0010
#define APPLESMC_RETRY_WAIT 0x0100
@@ -151,65 +161,88 @@ 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;
+ int loops = 0;
+ unsigned long end = jiffies + (APPLESMC_MAX_WAIT * HZ) / USEC_PER_SEC;

+ /* We always check for status ready */
+ val |= SMC_STATUS_READY;
+ mask |= SMC_STATUS_READY;
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;
- }
-
- pr_warn("wait_read() fail: 0x%02x\n", status);
+ usleep_range(us, us * 16);
+ loops += 1;
+ if (loops > 1)
+ pr_warn("wait_status looping %i: 0x%02x, 0x%02x, 0x%02x\n", loops, status, val, mask);
+ }
+ pr_warn("wait_status timeout: 0x%02x, 0x%02x, 0x%02x\n", status, val, mask);
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;
+ u8 wstat = 0;

+ if (!skip)
+ wstat |= SMC_STATUS_BUSY;
+ if (wait_status(SMC_STATUS_BUSY,
+ SMC_STATUS_BUSY | SMC_STATUS_IB_CLOSED))
+ goto fail;
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);
- }
-
- pr_warn("send_byte(0x%02x, 0x%04x) fail: 0x%02x\n", cmd, port, status);
+ if (!wait_status(wstat,
+ SMC_STATUS_READY | SMC_STATUS_GOT_COMMAND | SMC_STATUS_BUSY | SMC_STATUS_IB_CLOSED))
+ return 0;
+fail:
+ pr_warn("send_byte_data(0x%02x, 0x%04x) fail\n", cmd, APPLESMC_CMD_PORT);
return -EIO;
}

+/*
+ * send_command - Write a command to the SMC. Callers must hold applesmc_lock.
+ * If SMC is in undefined state, an new command write resets the state machine.
+ */
+
static int send_command(u8 cmd)
{
- return send_byte(cmd, APPLESMC_CMD_PORT);
+ u8 status;
+
+ if (wait_status(0,
+ SMC_STATUS_IB_CLOSED)) {
+ pr_warn("send_command fail 1\n");
+ goto fail; }
+
+ status = inb(APPLESMC_CMD_PORT);
+ if (status != 0x40)
+ pr_warn("At command start, Status was 0x%20x\n", status);
+
+ outb(cmd, APPLESMC_CMD_PORT);
+ if (wait_status(SMC_STATUS_BUSY | SMC_STATUS_GOT_COMMAND,
+ SMC_STATUS_GOT_COMMAND | SMC_STATUS_BUSY | SMC_STATUS_IB_CLOSED |
+ SMC_STATUS_AWAITING_DATA)) {
+ pr_warn("send_command fail 2\n");
+ goto fail; }
+ return 0;
+fail:
+ pr_warn("send_cmd(0x%02x, 0x%04x) fail\n", cmd, APPLESMC_CMD_PORT);
+ return -EIO;
}

static int send_argument(const char *key)
@@ -217,7 +250,8 @@ static int send_argument(const char *key)
int i;

for (i = 0; i < 4; i++)
- if (send_byte(key[i], APPLESMC_DATA_PORT))
+ /* Parameter skip is false as we always send data after an argument */
+ if (send_byte_data(key[i], APPLESMC_DATA_PORT, false))
return -EIO;
return 0;
}
@@ -233,13 +267,15 @@ static int read_smc(u8 cmd, const char *key, u8 *buffer, u8 len)
}

/* This has no effect on newer (2012) SMCs */
- if (send_byte(len, APPLESMC_DATA_PORT)) {
+ if (send_byte_data(len, APPLESMC_DATA_PORT, false)) {
pr_warn("%.4s: read len fail\n", key);
return -EIO;
}

for (i = 0; i < len; i++) {
- if (wait_read()) {
+ if (wait_status(SMC_STATUS_AWAITING_DATA | SMC_STATUS_BUSY,
+ SMC_STATUS_GOT_COMMAND | SMC_STATUS_BUSY | SMC_STATUS_IB_CLOSED |
+ SMC_STATUS_AWAITING_DATA)) {
pr_warn("%.4s: read data[%d] fail\n", key, i);
return -EIO;
}
@@ -250,7 +286,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);
}
@@ -269,14 +305,14 @@ static int write_smc(u8 cmd, const char *key, const u8 *buffer, u8 len)
return -EIO;
}

- if (send_byte(len, APPLESMC_DATA_PORT)) {
+ if (send_byte_data(len, APPLESMC_DATA_PORT, false)) {
pr_warn("%.4s: write len fail\n", key);
return -EIO;
}

for (i = 0; i < len; i++) {
- if (send_byte(buffer[i], APPLESMC_DATA_PORT)) {
- pr_warn("%s: write data fail\n", key);
+ if (send_byte_data(buffer[i], APPLESMC_DATA_PORT, (i == (len-1)))) {
+ pr_warn("%s: write data fail at %i\n", key, i);
return -EIO;
}
}