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

[Andreas Kemnade <andreas@kemnade.info>]

On Wed, 30 Sep 2020 22:00:09 +0200
Arnd Bergmann <arnd@arndb.de> wrote:

> On Wed, Sep 30, 2020 at 6:44 PM Guenter Roeck <linux@roeck-us.net> wrote:
> >
> > On Wed, Sep 30, 2020 at 10:54:42AM +0200, Andreas Kemnade wrote:  
> > > Hi,
> > >
> > > after the $subject patch I get lots of errors like this:  
> >
> > For reference, this refers to commit fff2d0f701e6 ("hwmon: (applesmc)
> > avoid overlong udelay()").
> >  
> > > [  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
> > >
> > > CPU sticks at low speed and no fan is turning on.
> > > Reverting this patch on top of 5.9-rc6 solves this problem.
> > >
> > > Some information from dmidecode:
> > >
> > > Base Board Information
> > >         Manufacturer: Apple Inc.
> > >         Product Name: Mac-7DF21CB3ED6977E5
> > >         Version: MacBookAir6,2
> > >
> > > Handle 0x0020, DMI type 11, 5 bytes OEM Strings         String 1: Apple ROM Version.  Model:       …,
> > > Handle 0x0020, DMI type 11, 5 bytes
> > > OEM Strings
> > >         String 1: Apple ROM Version.  Model:        MBA61.  EFI Version:  122.0.0
> > >         String 2: .0.0.  Built by:     root@saumon.  Date:         Wed Jun 10 18:
> > >         String 3: 10:36 PDT 2020.  Revision:     122 (B&I).  ROM Version:  F000_B
> > >         String 4: 00.  Build Type:   Official Build, Release.  Compiler:     Appl
> > >         String 5: e clang version 3.0 (tags/Apple/clang-211.10.1) (based on LLVM
> > >         String 6: 3.0svn).
> > >
> > > Writing to things in /sys/devices/platform/applesmc.768 gives also the
> > > said errors.
> > > But writing 1 to fan1_maunal and 5000 to fan1_output turns the fan on
> > > despite error messages.
> > >  
> > Not really sure what to do here. I could revert the patch, but then we'd gain
> > clang compile failures. Arnd, any idea ?  
> 
> It seems that either I made a mistake in the conversion and it sleeps for
> less time than before, or my assumption was wrong that converting a delay to
> a sleep is safe here.
> 
> The error message indicates that the write fails, not the read, so that
> is what I'd look at first. Right away I can see that the maximum time to
> retry is only half of what it used to be, as we used to wait for
> 0x10, 0x20, 0x40, 0x80, ..., 0x20000 microseconds for a total of
> 0x3fff0 microseconds (262ms), while my patch went with the 131ms
> total delay based on the comment saying "/* wait up to 128 ms for a
> status change. */".
> 
Yes, that is also what I read from the code. I just thought there must
be something simple, which just needs a short look from another pair of
eyes.

> Since there is sleeping wait, I see no reason the timeout couldn't
> be extended a lot, e.g. to a second, as in
> 
> #define APPLESMC_MAX_WAIT 0x100000
> 
> If that doesn't work, I'd try using mdelay() in place of
> usleep_range(), such as
> 
>            mdelay(DIV_ROUND_UP(us, USEC_PER_MSEC)));
> 
> This adds back a really nasty latency, but it should avoid the
> compile-time problem.
> 
> Andreas, can you try those two things? (one at a time,
> not both)

Ok, I tried. None of them works. I rechecked my work and created real
git commits out of them and CONFIG_LOCALVERSION_AUTO is also set so
the usual stupid things are rules out.
In detail:
On top of 5.9-rc6 + *reverted* patch:
diff --git a/drivers/hwmon/applesmc.c b/drivers/hwmon/applesmc.c
index fd99c9df8a00..2a9bd7f2b71b 100644
--- a/drivers/hwmon/applesmc.c
+++ b/drivers/hwmon/applesmc.c
@@ -45,7 +45,7 @@
 /* wait up to 128 ms for a status change. */
 #define APPLESMC_MIN_WAIT	0x0010
 #define APPLESMC_RETRY_WAIT	0x0100
-#define APPLESMC_MAX_WAIT	0x20000
+#define APPLESMC_MAX_WAIT	0x8000
 
 #define APPLESMC_READ_CMD	0x10
 #define APPLESMC_WRITE_CMD	0x11
-- 
2.20.1

-> no trouble found, but I have not tested very long, just some
sysfs writes.

On top of 5.9-rc6:
diff --git a/drivers/hwmon/applesmc.c b/drivers/hwmon/applesmc.c
index a18887990f4a..3b0108b75a24 100644
--- a/drivers/hwmon/applesmc.c
+++ b/drivers/hwmon/applesmc.c
@@ -161,7 +161,7 @@ static int wait_read(void)
 	int us;
 
 	for (us = APPLESMC_MIN_WAIT; us < APPLESMC_MAX_WAIT; us <<= 1) {
-		usleep_range(us, us * 16);
+		mdelay(DIV_ROUND_UP(us, USEC_PER_MSEC));
 		status = inb(APPLESMC_CMD_PORT);
 		/* read: wait for smc to settle */
 		if (status & 0x01)
@@ -187,7 +187,7 @@ static int send_byte(u8 cmd, u16 port)
 
 	outb(cmd, port);
 	for (us = APPLESMC_MIN_WAIT; us < APPLESMC_MAX_WAIT; us <<= 1) {
-		usleep_range(us, us * 16);
+		mdelay(DIV_ROUND_UP(us, USEC_PER_MSEC));
 		status = inb(APPLESMC_CMD_PORT);
 		/* write: wait for smc to settle */
 		if (status & 0x02)
-- 
2.20.1
-> write errors:

[    2.472801] applesmc: key=561 fan=1 temp=33 index=33 acc=0 lux=2 kbd=1
[    2.472961] applesmc applesmc.768: hwmon_device_register() is deprecated. Please convert the driver to use hwmon_device_register_with_info().
[   18.535659] applesmc: send_byte(0x00, 0x0300) fail: 0x40
[   18.538171] applesmc: LKSB: write data fail
[   45.260307] applesmc: send_byte(0x01, 0x0300) fail: 0x40
[   45.260324] applesmc: FS! : write data fail
[   47.870135] applesmc: send_byte(0x20, 0x0300) fail: 0x40
[   47.870193] applesmc: F0Tg: write data fail

On top of 5.9-rc6:
diff --git a/drivers/hwmon/applesmc.c b/drivers/hwmon/applesmc.c
index a18887990f4a..f67a25651d03 100644
--- a/drivers/hwmon/applesmc.c
+++ b/drivers/hwmon/applesmc.c
@@ -45,7 +45,7 @@
 /* wait up to 128 ms for a status change. */
 #define APPLESMC_MIN_WAIT	0x0010
 #define APPLESMC_RETRY_WAIT	0x0100
-#define APPLESMC_MAX_WAIT	0x20000
+#define APPLESMC_MAX_WAIT	0x100000
 
 #define APPLESMC_READ_CMD	0x10
 #define APPLESMC_WRITE_CMD	0x11
-- 
2.20.1

-> write errors:

[    1.428726] applesmc: key=561 fan=1 temp=33 index=33 acc=0 lux=2 kbd=1
[    1.428869] applesmc applesmc.768: hwmon_device_register() is deprecated. Please convert the driver to use hwmon_device_register_with_info().
[   19.672561] applesmc: send_byte(0x00, 0x0300) fail: 0x40
[   19.674641] applesmc: LKSB: write data fail
[   34.266216] applesmc: send_byte(0x01, 0x0300) fail: 0x40
[   34.266277] applesmc: FS! : write data fail
[   37.357023] applesmc: send_byte(0x20, 0x0300) fail: 0x40
[   37.357082] applesmc: F0Tg: write data fail

Accessing things in sysfs took longer, so the increase seems to be in effect.
Conclusion:

head->scratch();
So something requires really exact timings.

Regards,
Andreas